From 8a7812e989bbe16e90ab936372aa8dbc464b3e0c Mon Sep 17 00:00:00 2001 From: Krisztian Litkey Date: Tue, 14 Apr 2026 22:02:01 +0300 Subject: [PATCH 1/4] Makefile: update/fix ginkgo coverprofile command line option. Signed-off-by: Krisztian Litkey --- Makefile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Makefile b/Makefile index ca125fcd8..30fd0bf69 100644 --- a/Makefile +++ b/Makefile @@ -396,7 +396,7 @@ ginkgo-tests: --covermode atomic \ --output-dir $(COVERAGE_PATH) \ --junit-report junit.xml \ - --coverprofile $(COVERAGE_PATH)/coverprofile \ + --coverprofile coverprofile \ --keep-separate-coverprofiles \ --succinct \ --skip-package $$(echo $(GO_SUBPKGS) | tr -s '\t ' ',') \ From a0fd7e36876d7181a2f8b2f86479b8ae2fed55e1 Mon Sep 17 00:00:00 2001 From: Krisztian Litkey Date: Thu, 16 Apr 2026 10:53:00 +0300 Subject: [PATCH 2/4] go.mod,.github,build: bump golang and golangci-lint versions. Bump golang to v1.26.0 and golangci-lint to v2.11.4. Signed-off-by: Krisztian Litkey --- .github/workflows/lint.yaml | 4 ++-- Makefile | 2 +- cmd/config-manager/Dockerfile | 2 +- cmd/mpolset/Dockerfile | 2 +- cmd/plugins/balloons/Dockerfile | 2 +- cmd/plugins/memory-policy/Dockerfile | 2 +- cmd/plugins/memory-qos/Dockerfile | 2 +- cmd/plugins/memtierd/Dockerfile | 2 +- cmd/plugins/sgx-epc/Dockerfile | 2 +- cmd/plugins/template/Dockerfile | 2 +- cmd/plugins/topology-aware/Dockerfile | 2 +- cmd/resource-annotator/Dockerfile | 2 +- docs/Dockerfile | 2 +- go.mod | 2 +- 14 files changed, 15 insertions(+), 15 deletions(-) diff --git a/.github/workflows/lint.yaml b/.github/workflows/lint.yaml index 9f06365c2..c9c6f05d2 100644 --- a/.github/workflows/lint.yaml +++ b/.github/workflows/lint.yaml @@ -26,7 +26,7 @@ jobs: - uses: actions/setup-go@v5 with: go-version-file: go.mod - - uses: golangci/golangci-lint-action@v8 + - uses: golangci/golangci-lint-action@v9 with: - version: v2.4.0 + version: v2.11.4 args: --timeout=10m diff --git a/Makefile b/Makefile index 30fd0bf69..7191fba3f 100644 --- a/Makefile +++ b/Makefile @@ -37,7 +37,7 @@ GO_LINT := golint -set_exit_status GO_FMT := gofmt GO_VET := $(GO_CMD) vet GO_DEPS := $(GO_CMD) list -f '{{ join .Deps "\n" }}' -GO_VERSION ?= 1.25.0 +GO_VERSION ?= 1.26.0 GO_MODULES := $(shell $(GO_CMD) list ./...) GO_SUBPKGS := $(shell find ./pkg -name go.mod | sed 's:/go.mod::g' | grep -v testdata | \ diff --git a/cmd/config-manager/Dockerfile b/cmd/config-manager/Dockerfile index c24e54500..670cd0252 100644 --- a/cmd/config-manager/Dockerfile +++ b/cmd/config-manager/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/mpolset/Dockerfile b/cmd/mpolset/Dockerfile index 3f38f0c79..1ba23f320 100644 --- a/cmd/mpolset/Dockerfile +++ b/cmd/mpolset/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/balloons/Dockerfile b/cmd/plugins/balloons/Dockerfile index 05681ef88..d81fe949c 100644 --- a/cmd/plugins/balloons/Dockerfile +++ b/cmd/plugins/balloons/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/memory-policy/Dockerfile b/cmd/plugins/memory-policy/Dockerfile index 6d7f043f9..a39b85c62 100644 --- a/cmd/plugins/memory-policy/Dockerfile +++ b/cmd/plugins/memory-policy/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/memory-qos/Dockerfile b/cmd/plugins/memory-qos/Dockerfile index bb3ca802e..69bcf1318 100644 --- a/cmd/plugins/memory-qos/Dockerfile +++ b/cmd/plugins/memory-qos/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/memtierd/Dockerfile b/cmd/plugins/memtierd/Dockerfile index b30d6f0f3..c244575fe 100644 --- a/cmd/plugins/memtierd/Dockerfile +++ b/cmd/plugins/memtierd/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/sgx-epc/Dockerfile b/cmd/plugins/sgx-epc/Dockerfile index dfe3978a3..f875789c6 100644 --- a/cmd/plugins/sgx-epc/Dockerfile +++ b/cmd/plugins/sgx-epc/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/template/Dockerfile b/cmd/plugins/template/Dockerfile index e611ecd6a..28fed40a1 100644 --- a/cmd/plugins/template/Dockerfile +++ b/cmd/plugins/template/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/plugins/topology-aware/Dockerfile b/cmd/plugins/topology-aware/Dockerfile index 9df8599e9..993d9513f 100644 --- a/cmd/plugins/topology-aware/Dockerfile +++ b/cmd/plugins/topology-aware/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/cmd/resource-annotator/Dockerfile b/cmd/resource-annotator/Dockerfile index 13061b0b8..caa38fe61 100644 --- a/cmd/resource-annotator/Dockerfile +++ b/cmd/resource-annotator/Dockerfile @@ -1,4 +1,4 @@ -ARG GO_VERSION=1.25 +ARG GO_VERSION=1.26 FROM golang:${GO_VERSION}-bookworm AS builder diff --git a/docs/Dockerfile b/docs/Dockerfile index fd327ec90..3c596fbba 100644 --- a/docs/Dockerfile +++ b/docs/Dockerfile @@ -1,6 +1,6 @@ FROM sphinxdoc/sphinx:7.4.7 -ARG GO_VERSION=1.25.0 +ARG GO_VERSION=1.26.0 RUN apt-get update && apt-get install -y wget git diff --git a/go.mod b/go.mod index 56e3c99ec..ef04cf5a0 100644 --- a/go.mod +++ b/go.mod @@ -1,6 +1,6 @@ module github.com/containers/nri-plugins -go 1.25.0 +go 1.26.0 require ( github.com/askervin/gofmbt v0.0.0-20250119175120-506d925f666f From 0777ae631a080e582d2ff9d5f981a376c33da8f1 Mon Sep 17 00:00:00 2001 From: Krisztian Litkey Date: Wed, 15 Apr 2026 11:16:06 +0300 Subject: [PATCH 3/4] all: use log.{Debug,Info,Warn,Error}f consistently everywhere. Use log.Debugf, log.Infof, log.Warnf, and log.Errorf consistently everywhere for formatted logging. Signed-off-by: Krisztian Litkey --- .../balloons/policy/balloons-policy.go | 98 +++--- .../template/policy/template-policy.go | 12 +- cmd/plugins/topology-aware/policy/affinity.go | 12 +- cmd/plugins/topology-aware/policy/cache.go | 14 +- .../topology-aware/policy/coldstart.go | 16 +- cmd/plugins/topology-aware/policy/hint.go | 8 +- cmd/plugins/topology-aware/policy/metrics.go | 4 +- cmd/plugins/topology-aware/policy/node.go | 26 +- .../topology-aware/policy/node_test.go | 26 +- .../topology-aware/policy/pod-preferences.go | 36 +-- cmd/plugins/topology-aware/policy/pools.go | 280 +++++++++--------- .../topology-aware/policy/resources.go | 38 +-- .../policy/topology-aware-policy.go | 36 +-- cmd/resource-annotator/webhook.go | 2 +- pkg/agent/agent.go | 38 +-- pkg/agent/node-resource-topology.go | 4 +- pkg/agent/pod-resource-api.go | 4 +- pkg/agent/podresapi/resources.go | 2 +- pkg/agent/watch/file.go | 4 +- pkg/agent/watch/object.go | 8 +- pkg/apis/resmgr/v1alpha1/expression.go | 16 +- pkg/cpuallocator/allocator.go | 196 ++++++------ pkg/http/http.go | 26 +- pkg/instrumentation/instrumentation.go | 4 +- pkg/instrumentation/metrics/metrics.go | 14 +- pkg/instrumentation/tracing/tracing.go | 4 +- pkg/resmgr/cache/affinity.go | 6 +- pkg/resmgr/cache/cache.go | 38 +-- pkg/resmgr/cache/container.go | 88 +++--- pkg/resmgr/cache/pod.go | 20 +- pkg/resmgr/cache/utils.go | 2 +- pkg/resmgr/control/control.go | 6 +- pkg/resmgr/control/cpu/api.go | 6 +- pkg/resmgr/control/cpu/cache.go | 2 +- pkg/resmgr/control/cpu/cpu.go | 32 +- pkg/resmgr/control/e2e-test/e2e-test.go | 18 +- pkg/resmgr/events.go | 6 +- pkg/resmgr/lib/memory/allocator.go | 38 +-- pkg/resmgr/lib/memory/logging.go | 34 +-- pkg/resmgr/lib/memory/mask-cache.go | 16 +- pkg/resmgr/lib/memory/request.go | 2 +- pkg/resmgr/lib/memory/zones.go | 10 +- pkg/resmgr/nri.go | 144 ++++----- pkg/resmgr/policy/policy.go | 6 +- pkg/resmgr/rdt.go | 6 +- pkg/resmgr/resource-manager.go | 12 +- pkg/sysfs/parsers_test.go | 16 +- pkg/sysfs/system.go | 108 +++---- pkg/udev/doc.go | 2 +- pkg/udev/reader.go | 2 +- scripts/udev-monitor/udev-monitor.go | 2 +- 51 files changed, 775 insertions(+), 775 deletions(-) diff --git a/cmd/plugins/balloons/policy/balloons-policy.go b/cmd/plugins/balloons/policy/balloons-policy.go index 53f59fe6a..a1de819f5 100644 --- a/cmd/plugins/balloons/policy/balloons-policy.go +++ b/cmd/plugins/balloons/policy/balloons-policy.go @@ -216,18 +216,18 @@ func (p *balloons) Setup(policyOptions *policy.BackendOptions) error { p.cch = policyOptions.Cache p.cpuAllocator = cpuallocator.NewCPUAllocator(policyOptions.System) - log.Info("setting up %s policy...", PolicyName) + log.Infof("setting up %s policy...", PolicyName) if p.cpuTree, err = NewCpuTreeFromSystem(); err != nil { log.Errorf("creating CPU topology tree failed: %s", err) } - log.Debug("CPU topology: %s", p.cpuTree) + log.Debugf("CPU topology: %s", p.cpuTree) // Handle policy-specific options - log.Debug("creating %s configuration", PolicyName) + log.Debugf("creating %s configuration", PolicyName) if err := p.setConfig(bpoptions); err != nil { return balloonsError("failed to create %s policy: %v", PolicyName, err) } - log.Debug("first effective configuration:\n%s\n", utils.DumpJSON(p.bpoptions)) + log.Debugf("first effective configuration:\n%s\n", utils.DumpJSON(p.bpoptions)) return nil } @@ -244,7 +244,7 @@ func (p *balloons) Description() string { // Start prepares this policy for accepting allocation/release requests. func (p *balloons) Start() error { - log.Info("%s policy started", PolicyName) + log.Infof("%s policy started", PolicyName) return nil } @@ -253,7 +253,7 @@ func (p *balloons) Sync(add []cache.Container, del []cache.Container) error { p.BlockMeters() defer p.UnblockMeters() - log.Debug("synchronizing state...") + log.Debugf("synchronizing state...") for _, c := range del { if err := p.ReleaseResources(c); err != nil { log.Warnf("releasing resources for Sync produced an error: %v", err) @@ -291,7 +291,7 @@ func (p *balloons) AllocateResources(c cache.Container) error { } } - log.Debug("allocating resources for container %s (request %d mCPU, limit %d mCPU)...", + log.Debugf("allocating resources for container %s (request %d mCPU, limit %d mCPU)...", c.PrettyName(), p.containerRequestedMilliCpus(c.GetID()), p.containerLimitedMilliCpus(c.GetID())) @@ -318,7 +318,7 @@ func (p *balloons) AllocateResources(c cache.Container) error { } p.assignContainer(c, bln) if log.DebugEnabled() { - log.Debug(p.dumpBalloon(bln)) + log.Debugf(p.dumpBalloon(bln)) } return nil @@ -329,11 +329,11 @@ func (p *balloons) ReleaseResources(c cache.Container) error { p.BlockMeters() defer p.UnblockMeters() - log.Debug("releasing container %s...", c.PrettyName()) + log.Debugf("releasing container %s...", c.PrettyName()) if bln := p.balloonByContainer(c); bln != nil { p.dismissContainer(c, bln) if log.DebugEnabled() { - log.Debug(p.dumpBalloon(bln)) + log.Debugf(p.dumpBalloon(bln)) } if bln.ContainerCount() == 0 { // Deflate the balloon completely before @@ -341,7 +341,7 @@ func (p *balloons) ReleaseResources(c cache.Container) error { if err := p.resizeBalloon(bln, 0); err != nil { log.Warnf("failed to deflate balloon %s: %v", bln.PrettyName(), err) } - log.Debug("all containers removed, free balloon allocation %s", bln.PrettyName()) + log.Debugf("all containers removed, free balloon allocation %s", bln.PrettyName()) p.freeBalloon(bln) } else { // Make sure that the balloon will have at @@ -351,7 +351,7 @@ func (p *balloons) ReleaseResources(c cache.Container) error { } } } else { - log.Debug("ReleaseResources: balloon-less container %s, nothing to release", c.PrettyName()) + log.Debugf("ReleaseResources: balloon-less container %s, nothing to release", c.PrettyName()) } return nil @@ -362,13 +362,13 @@ func (p *balloons) UpdateResources(c cache.Container) error { p.BlockMeters() defer p.UnblockMeters() - log.Debug("(not) updating container %s...", c.PrettyName()) + log.Debugf("(not) updating container %s...", c.PrettyName()) return nil } // HandleEvent handles policy-specific events. func (p *balloons) HandleEvent(*events.Policy) (bool, error) { - log.Debug("(not) handling event...") + log.Debugf("(not) handling event...") return false, nil } @@ -913,7 +913,7 @@ func (p *balloons) updateLoadedVirtDev(allocatorOptions *cpuTreeAllocatorOptions // device CPUs allocatorOptions.virtDevCpusets[virtDevName] = []cpuset.CPUSet{prevCpus.Union(p.cpuTree.system().AllCPUsSharingNthLevelCacheWithCPUs(2, vdCpus))} default: - log.Error("internal error: not implemented load level %q used in virtual device %q", virtDev.level, virtDevName) + log.Errorf("internal error: not implemented load level %q used in virtual device %q", virtDev.level, virtDevName) } log.Debugf(" loaded virtual device %q on CPUs %q affects CPUs %q", virtDev.name, vdCpus, allocatorOptions.virtDevCpusets[virtDevName]) } @@ -1444,16 +1444,16 @@ func (p *balloons) Reconfigure(newCfg interface{}) error { return balloonsError("config data of unexpected type %T", newCfg) } - log.Info("configuration update") + log.Infof("configuration update") defer func() { - log.Debug("effective configuration:\n%s\n", utils.DumpJSON(p.bpoptions)) + log.Debugf("effective configuration:\n%s\n", utils.DumpJSON(p.bpoptions)) }() newBalloonsOptions := balloonsOptions.DeepCopy() if !changesBalloons(p.bpoptions, newBalloonsOptions) { if !changesCpuClasses(p.bpoptions, newBalloonsOptions) { - log.Info("no configuration changes") + log.Infof("no configuration changes") } else { - log.Info("configuration changes only on CPU classes") + log.Infof("configuration changes only on CPU classes") // Update new CPU classes to existing balloon // definitions. The same BalloonDef instances // must be kept in use, because each Balloon @@ -1475,10 +1475,10 @@ func (p *balloons) Reconfigure(newCfg interface{}) error { return nil } if err := p.setConfig(newBalloonsOptions); err != nil { - log.Error("config update failed: %v", err) + log.Errorf("config update failed: %v", err) return err } - log.Info("config updated successfully") + log.Infof("config updated successfully") if err := p.Sync(p.cch.GetContainers(), p.cch.GetContainers()); err != nil { log.Warnf("failed to sync containers: %v", err) } @@ -1537,7 +1537,7 @@ func (p *balloons) validateConfig(bpoptions *BalloonsOptions) error { } } if blnDef.PreferIsolCpus && blnDef.ShareIdleCpusInSame != "" { - log.Warn("WARNING: using PreferIsolCpus with ShareIdleCpusInSame is highly discouraged") + log.Warnf("WARNING: using PreferIsolCpus with ShareIdleCpusInSame is highly discouraged") } if len(blnDef.Components) > 0 { compositeBlnDefs[blnDef.Name] = blnDef @@ -1713,9 +1713,9 @@ func (p *balloons) setConfig(bpoptions *BalloonsOptions) error { p.ifreeCpus = p.freeCpus.Clone() // Finish balloon instance initialization. - log.Info("%s policy balloons:", PolicyName) + log.Infof("%s policy balloons:", PolicyName) for blnIdx, bln := range p.balloons { - log.Info("- balloon %d: %s", blnIdx, bln) + log.Infof("- balloon %d: %s", blnIdx, bln) } p.updatePinning(p.shareIdleCpus(p.freeCpus, cpuset.New())...) // (Re)configures all CPUs in balloons. @@ -2154,54 +2154,54 @@ func applyProcessScheduling(c cache.Container, sc *SchedulingClass) { if sc == nil { return } - log.Debug(" - applying scheduling class %q to %s", sc.Name, c.PrettyName()) + log.Debugf(" - applying scheduling class %q to %s", sc.Name, c.PrettyName()) if sc.Policy != "" { if pol, err := sc.Policy.ToNRI(); err == nil { c.SetSchedulingPolicy(pol) - log.Debug(" - scheduling policy %q (%s)", sc.Policy, pol) + log.Debugf(" - scheduling policy %q (%s)", sc.Policy, pol) } else { - log.Debug(" - invalid scheduling policy %q in scheduling class %q: %v", sc.Policy, sc.Name, err) + log.Debugf(" - invalid scheduling policy %q in scheduling class %q: %v", sc.Policy, sc.Name, err) } } if sc.Priority != nil { c.SetSchedulingPriority(int32(*sc.Priority)) - log.Debug(" - scheduling priority %d", *sc.Priority) + log.Debugf(" - scheduling priority %d", *sc.Priority) } if len(sc.Flags) > 0 { if flags, err := sc.Flags.ToNRI(); err == nil { c.SetSchedulingFlags(flags) - log.Debug(" - scheduling flags %q", sc.Flags) + log.Debugf(" - scheduling flags %q", sc.Flags) } else { - log.Debug(" - invalid scheduling flags %q in scheduling class %q: %v", sc.Flags, sc.Name, err) + log.Debugf(" - invalid scheduling flags %q in scheduling class %q: %v", sc.Flags, sc.Name, err) } } if sc.Nice != nil { c.SetSchedulingNice(int32(*sc.Nice)) - log.Debug(" - nice value %d", *sc.Nice) + log.Debugf(" - nice value %d", *sc.Nice) } if sc.Runtime != nil { c.SetSchedulingRuntime(*sc.Runtime) - log.Debug(" - scheduling runtime %d", *sc.Runtime) + log.Debugf(" - scheduling runtime %d", *sc.Runtime) } if sc.Deadline != nil { c.SetSchedulingDeadline(*sc.Deadline) - log.Debug(" - scheduling deadline %d", *sc.Deadline) + log.Debugf(" - scheduling deadline %d", *sc.Deadline) } if sc.Period != nil { c.SetSchedulingPeriod(*sc.Period) - log.Debug(" - scheduling period %d", *sc.Period) + log.Debugf(" - scheduling period %d", *sc.Period) } if sc.IOClass != "" { if ioClass, err := sc.IOClass.ToNRI(); err == nil { c.SetSchedulingIOClass(ioClass) - log.Debug(" - IO class %q", sc.IOClass) + log.Debugf(" - IO class %q", sc.IOClass) } else { - log.Debug(" - invalid IO class %q in scheduling class %q: %v", sc.IOClass, sc.Name, err) + log.Debugf(" - invalid IO class %q in scheduling class %q: %v", sc.IOClass, sc.Name, err) } } if sc.IOPriority != nil { c.SetSchedulingIOPriority(int32(*sc.IOPriority)) - log.Debug(" - IO priority %d", *sc.IOPriority) + log.Debugf(" - IO priority %d", *sc.IOPriority) } } @@ -2209,7 +2209,7 @@ func (p *balloons) applyProcessProperties(c cache.Container, bln *Balloon) { effSc := bln.Def.SchedulingClass if annSc, annExists := c.GetEffectiveAnnotation(schedulingClassKey); annExists { if annSc != effSc { - log.Debug(" - container %s overrides balloon scheduling class %q with annotation %q", + log.Debugf(" - container %s overrides balloon scheduling class %q with annotation %q", c.PrettyName(), effSc, annSc) } effSc = annSc @@ -2226,7 +2226,7 @@ func (p *balloons) applyProcessProperties(c cache.Container, bln *Balloon) { // assignContainer adds a container to a balloon func (p *balloons) assignContainer(c cache.Container, bln *Balloon) { - log.Info("assigning container %s to balloon %s", c.PrettyName(), bln) + log.Infof("assigning container %s to balloon %s", c.PrettyName(), bln) podID := c.GetPodID() bln.PodIDs[podID] = append(bln.PodIDs[podID], c.GetID()) bln.updateGroups(c, 1) @@ -2237,7 +2237,7 @@ func (p *balloons) assignContainer(c cache.Container, bln *Balloon) { // dismissContainer removes a container from a balloon func (p *balloons) dismissContainer(c cache.Container, bln *Balloon) { if err := p.memAllocator.Release(c.GetID()); err != nil { - log.Error("dismissContainer: failed to release memory for %s: %v", c.PrettyName(), err) + log.Errorf("dismissContainer: failed to release memory for %s: %v", c.PrettyName(), err) } podID := c.GetPodID() bln.PodIDs[podID] = removeString(bln.PodIDs[podID], c.GetID()) @@ -2250,7 +2250,7 @@ func (p *balloons) dismissContainer(c cache.Container, bln *Balloon) { // pinCpuMem pins container to CPUs and memory nodes if flagged func (p *balloons) pinCpuMem(c cache.Container, cpus cpuset.CPUSet, mems idset.IDSet, memTypeMask libmem.TypeMask, blnDefPinMemory *bool) { if p.bpoptions.PinCPU == nil || *p.bpoptions.PinCPU { - log.Debug(" - pinning %s to cpuset: %s", c.PrettyName(), cpus) + log.Debugf(" - pinning %s to cpuset: %s", c.PrettyName(), cpus) c.SetCpusetCpus(cpus.String()) if reqCpu, ok := c.GetResourceRequirements().Requests[corev1.ResourceCPU]; ok { mCpu := int(reqCpu.MilliValue()) @@ -2265,32 +2265,32 @@ func (p *balloons) pinCpuMem(c cache.Container, cpus cpuset.CPUSet, mems idset.I } if pinMemory { if c.PreserveMemoryResources() { - log.Debug(" - preserving %s pinning to memory %q", c.PrettyName, c.GetCpusetMems()) + log.Debugf(" - preserving %s pinning to memory %q", c.PrettyName, c.GetCpusetMems()) preserveMems, err := parseIDSet(c.GetCpusetMems()) if err != nil { - log.Error("failed to parse CpusetMems: %v", err) + log.Errorf("failed to parse CpusetMems: %v", err) } else { zone := p.allocMem(c, preserveMems, 0, true) - log.Debug(" - allocated preserved memory %s", c.PrettyName, zone) + log.Debugf(" - allocated preserved memory %s", c.PrettyName, zone) c.SetCpusetMems(zone.MemsetString()) } } else { effMemTypeMask, err := c.MemoryTypes() if err != nil { - log.Error("%v", err) + log.Errorf("%v", err) } if effMemTypeMask != 0 { // memory-type pod/container-specific // annotation overrides balloon's // memory options that are the default // to all containers in the balloon. - log.Debug(" - %s memory-type annotation mask %s overrides balloon mems %s and mask %s", c.PrettyName(), effMemTypeMask, mems, memTypeMask) + log.Debugf(" - %s memory-type annotation mask %s overrides balloon mems %s and mask %s", c.PrettyName(), effMemTypeMask, mems, memTypeMask) } else { effMemTypeMask = memTypeMask } - log.Debug(" - requested %s to memory %s (types %s)", c.PrettyName(), mems, effMemTypeMask) + log.Debugf(" - requested %s to memory %s (types %s)", c.PrettyName(), mems, effMemTypeMask) zone := p.allocMem(c, mems, effMemTypeMask, false) - log.Debug(" - allocated %s to memory %s", c.PrettyName(), zone) + log.Debugf(" - allocated %s to memory %s", c.PrettyName(), zone) c.SetCpusetMems(zone.MemsetString()) } } @@ -2331,7 +2331,7 @@ func (p *balloons) allocMem(c cache.Container, mems idset.IDSet, types libmem.Ty } if err != nil { - log.Error("allocMem: falling back to %s, failed to allocate memory for %s: %v", + log.Errorf("allocMem: falling back to %s, failed to allocate memory for %s: %v", nodes, c.PrettyName(), err) return nodes } diff --git a/cmd/plugins/template/policy/template-policy.go b/cmd/plugins/template/policy/template-policy.go index b1684ba7d..4a31092b9 100644 --- a/cmd/plugins/template/policy/template-policy.go +++ b/cmd/plugins/template/policy/template-policy.go @@ -70,7 +70,7 @@ func (p *policy) Setup(opts *policyapi.BackendOptions) error { // Start prepares this policy for accepting allocation/release requests. func (p *policy) Start() error { - log.Info("started...") + log.Infof("started...") return nil } @@ -86,31 +86,31 @@ func (p *policy) Reconfigure(newCfg interface{}) error { // Sync synchronizes the state of this policy. func (p *policy) Sync(add []cache.Container, del []cache.Container) error { - log.Info("synchronizing state...") + log.Infof("synchronizing state...") return nil } // AllocateResources is a resource allocation request for this policy. func (p *policy) AllocateResources(container cache.Container) error { - log.Info("allocating resources for %s...", container.PrettyName()) + log.Infof("allocating resources for %s...", container.PrettyName()) return nil } // ReleaseResources is a resource release request for this policy. func (p *policy) ReleaseResources(container cache.Container) error { - log.Info("releasing resources of %s...", container.PrettyName()) + log.Infof("releasing resources of %s...", container.PrettyName()) return nil } // UpdateResources is a resource allocation update request for this policy. func (p *policy) UpdateResources(c cache.Container) error { - log.Info("(not) updating container %s...", c.PrettyName()) + log.Infof("(not) updating container %s...", c.PrettyName()) return nil } // HandleEvent handles policy-specific events. func (p *policy) HandleEvent(e *events.Policy) (bool, error) { - log.Info("received policy event %s.%s with data %v...", e.Source, e.Type, e.Data) + log.Infof("received policy event %s.%s with data %v...", e.Source, e.Type, e.Data) return true, nil } diff --git a/cmd/plugins/topology-aware/policy/affinity.go b/cmd/plugins/topology-aware/policy/affinity.go index 5cba1eb39..5cf720b9e 100644 --- a/cmd/plugins/topology-aware/policy/affinity.go +++ b/cmd/plugins/topology-aware/policy/affinity.go @@ -21,7 +21,7 @@ import ( // Calculate pool affinities for the given container. func (p *policy) calculatePoolAffinities(container cache.Container) (map[int]int32, error) { - log.Debug("=> calculating pool affinities...") + log.Debugf("=> calculating pool affinities...") affinities, err := p.calculateContainerAffinity(container) if err != nil { @@ -45,7 +45,7 @@ func (p *policy) calculatePoolAffinities(container cache.Container) (map[int]int // Calculate affinity of this container (against all other containers). func (p *policy) calculateContainerAffinity(container cache.Container) (map[string]int32, error) { - log.Debug("* calculating affinity for container %s...", container.PrettyName()) + log.Debugf("* calculating affinity for container %s...", container.PrettyName()) ca, err := container.GetAffinity() if err != nil { @@ -62,7 +62,7 @@ func (p *policy) calculateContainerAffinity(container cache.Container) (map[stri // self-affinity does not make sense, so remove any delete(result, container.GetID()) - log.Debug(" => affinity: %v", result) + log.Debugf(" => affinity: %v", result) return result, nil } @@ -83,7 +83,7 @@ func (p *policy) registerImplicitAffinities() error { } pod, ok := c.GetPod() if !ok { - log.Error("failed to inject pod-colocation affinity, can't find pod") + log.Errorf("failed to inject pod-colocation affinity, can't find pod") return nil } return &cache.Affinity{ @@ -129,10 +129,10 @@ func (p *policy) registerImplicitAffinities() error { del = append(del, name) if !a.disabled { - log.Info("implicit affinity %s is enabled", a.name) + log.Infof("implicit affinity %s is enabled", a.name) add[name] = a.affinity } else { - log.Info("implicit affinity %s is disabled", a.name) + log.Infof("implicit affinity %s is disabled", a.name) } } diff --git a/cmd/plugins/topology-aware/policy/cache.go b/cmd/plugins/topology-aware/policy/cache.go index 454cb8bd6..b8c7706ef 100644 --- a/cmd/plugins/topology-aware/policy/cache.go +++ b/cmd/plugins/topology-aware/policy/cache.go @@ -49,7 +49,7 @@ func (p *policy) restoreAllocations(allocations *allocations) error { // if err := p.reinstateGrants(allocations.grants); err != nil { - log.Error("failed to reinstate grants verbatim: %v", err) + log.Errorf("failed to reinstate grants verbatim: %v", err) containers, poolHints := allocations.getContainerPoolHints() if err := p.reallocateResources(containers, poolHints); err != nil { p.allocations = savedAllocations @@ -77,7 +77,7 @@ func (p *policy) reinstateGrants(grants map[string]Grant) error { for id, grant := range grants { if err := p.releaseMem(id); err != nil && !errors.Is(err, libmem.ErrUnknownRequest) { - log.Error("failed to release memory for grant %s: %v", grant, err) + log.Errorf("failed to release memory for grant %s: %v", grant, err) } } @@ -101,18 +101,18 @@ func (p *policy) reinstateGrants(grants map[string]Grant) error { for uID, uZone := range updates { if ug, ok := p.allocations.grants[uID]; !ok { - log.Error("failed to update grant %s to memory zone to %s, grant not found", + log.Errorf("failed to update grant %s to memory zone to %s, grant not found", uID, uZone) } else { ug.SetMemoryZone(uZone) if opt.PinMemory { ug.GetContainer().SetCpusetMems(uZone.MemsetString()) } - log.Info("updated grant %s to memory zone %s", uID, uZone) + log.Infof("updated grant %s to memory zone %s", uID, uZone) } } - log.Info("updated pool %q with reinstated CPU grant of %q, memory zone %s", + log.Infof("updated pool %q with reinstated CPU grant of %q, memory zone %s", pool.Name(), c.PrettyName(), grant.GetMemoryZone()) p.allocations.grants[id] = grant @@ -216,10 +216,10 @@ func (a *allocations) UnmarshalJSON(data []byte) error { for id, ccg := range cgrants { a.grants[id], err = ccg.ToGrant(a.policy) if err != nil { - log.Error("removing unresolvable cached grant %v: %v", *ccg, err) + log.Errorf("removing unresolvable cached grant %v: %v", *ccg, err) delete(a.grants, id) } else { - log.Debug("resolved cache grant: %v", a.grants[id].String()) + log.Debugf("resolved cache grant: %v", a.grants[id].String()) } } diff --git a/cmd/plugins/topology-aware/policy/coldstart.go b/cmd/plugins/topology-aware/policy/coldstart.go index f369ab14e..9f81d2da0 100644 --- a/cmd/plugins/topology-aware/policy/coldstart.go +++ b/cmd/plugins/topology-aware/policy/coldstart.go @@ -24,16 +24,16 @@ import ( // trigger cold start for the container if necessary. func (p *policy) triggerColdStart(c cache.Container) error { - log.Info("coldstart: triggering coldstart for %s...", c.PrettyName()) + log.Infof("coldstart: triggering coldstart for %s...", c.PrettyName()) g, ok := p.allocations.grants[c.GetID()] if !ok { - log.Warn("coldstart: no grant found, nothing to do...") + log.Warnf("coldstart: no grant found, nothing to do...") return nil } coldStart := g.ColdStart() if coldStart <= 0 { - log.Info("coldstart: no coldstart, nothing to do...") + log.Infof("coldstart: no coldstart, nothing to do...") return nil } @@ -49,7 +49,7 @@ func (p *policy) triggerColdStart(c cache.Container) error { } if err := p.options.SendEvent(e); err != nil { // we should retry this later, the channel is probably full... - log.Error("Ouch... we'should retry this later.") + log.Errorf("Ouch... we'should retry this later.") } }) g.AddTimer(timer) @@ -60,16 +60,16 @@ func (p *policy) triggerColdStart(c cache.Container) error { func (p *policy) finishColdStart(c cache.Container) (bool, error) { g, ok := p.allocations.grants[c.GetID()] if !ok { - log.Warn("coldstart: no grant found, nothing to do...") + log.Warnf("coldstart: no grant found, nothing to do...") return false, policyError("coldstart: no grant found for %s", c.PrettyName()) } - log.Info("reallocating %s after coldstart", g) + log.Infof("reallocating %s after coldstart", g) err := g.ReallocMemory(p.memZoneType(g.GetMemoryZone()) | libmem.TypeMaskDRAM) if err != nil { - log.Error("failed to reallocate %s after coldstart: %v", g, err) + log.Errorf("failed to reallocate %s after coldstart: %v", g, err) } else { - log.Info("reallocated %s", g) + log.Infof("reallocated %s", g) } g.ClearTimer() diff --git a/cmd/plugins/topology-aware/policy/hint.go b/cmd/plugins/topology-aware/policy/hint.go index 4e378e737..a975d90c5 100644 --- a/cmd/plugins/topology-aware/policy/hint.go +++ b/cmd/plugins/topology-aware/policy/hint.go @@ -28,7 +28,7 @@ import ( func cpuHintScore(hint topology.Hint, CPUs cpuset.CPUSet) float64 { hCPUs, err := cpuset.Parse(hint.CPUs) if err != nil { - log.Warn("invalid hint CPUs '%s' from %s", hint.CPUs, hint.Provider) + log.Warnf("invalid hint CPUs '%s' from %s", hint.CPUs, hint.Provider) return 0.0 } common := hCPUs.Intersection(CPUs) @@ -40,7 +40,7 @@ func numaHintScore(hint topology.Hint, sysIDs ...idset.ID) float64 { for _, idstr := range strings.Split(hint.NUMAs, ",") { hID, err := strconv.ParseInt(idstr, 0, 0) if err != nil { - log.Warn("invalid hint NUMA node %s from %s", idstr, hint.Provider) + log.Warnf("invalid hint NUMA node %s from %s", idstr, hint.Provider) return 0.0 } @@ -61,7 +61,7 @@ func dieHintScore(hint topology.Hint, sysID idset.ID, socket system.CPUPackage) for _, idstr := range strings.Split(hint.NUMAs, ",") { hID, err := strconv.ParseInt(idstr, 0, 0) if err != nil { - log.Warn("invalid hint NUMA node %s from %s", idstr, hint.Provider) + log.Warnf("invalid hint NUMA node %s from %s", idstr, hint.Provider) return 0.0 } @@ -78,7 +78,7 @@ func socketHintScore(hint topology.Hint, sysID idset.ID) float64 { for _, idstr := range strings.Split(hint.Sockets, ",") { id, err := strconv.ParseInt(idstr, 0, 0) if err != nil { - log.Warn("invalid hint socket '%s' from %s", idstr, hint.Provider) + log.Warnf("invalid hint socket '%s' from %s", idstr, hint.Provider) return 0.0 } if id == int64(sysID) { diff --git a/cmd/plugins/topology-aware/policy/metrics.go b/cmd/plugins/topology-aware/policy/metrics.go index f86d3f0f1..bf9d64eb4 100644 --- a/cmd/plugins/topology-aware/policy/metrics.go +++ b/cmd/plugins/topology-aware/policy/metrics.go @@ -208,7 +208,7 @@ func (m *TopologyAwareMetrics) Update() { p := m.p for _, pool := range p.pools { - log.Debug("updating metrics for pool %s...", pool.Name()) + log.Debugf("updating metrics for pool %s...", pool.Name()) var ( zone = m.Zones[pool.Name()] @@ -220,7 +220,7 @@ func (m *TopologyAwareMetrics) Update() { ) if zone == nil { - log.Error("metrics zone not found for pool %s", pool.Name()) + log.Errorf("metrics zone not found for pool %s", pool.Name()) continue } diff --git a/cmd/plugins/topology-aware/policy/node.go b/cmd/plugins/topology-aware/policy/node.go index 2a4cc24cc..4d71d109b 100644 --- a/cmd/plugins/topology-aware/policy/node.go +++ b/cmd/plugins/topology-aware/policy/node.go @@ -333,27 +333,27 @@ func (n *node) Dump(prefix string, level ...int) { idt := indent(prefix, lvl) n.self.node.dump(prefix, lvl) - log.Debug("%s - %s", idt, n.noderes.DumpCapacity()) - log.Debug("%s - %s", idt, n.freeres.DumpAllocatable()) + log.Debugf("%s - %s", idt, n.noderes.DumpCapacity()) + log.Debugf("%s - %s", idt, n.freeres.DumpAllocatable()) if n.mem.Size() > 0 { - log.Debug("%s - normal memory: %v", idt, n.mem) + log.Debugf("%s - normal memory: %v", idt, n.mem) } if n.hbm.Size() > 0 { - log.Debug("%s - HBM memory: %v", idt, n.hbm) + log.Debugf("%s - HBM memory: %v", idt, n.hbm) } if n.pMem.Size() > 0 { - log.Debug("%s - PMEM memory: %v", idt, n.pMem) + log.Debugf("%s - PMEM memory: %v", idt, n.pMem) } for _, grant := range n.policy.allocations.grants { if grant.GetCPUNode().NodeID() == n.id { - log.Debug("%s + %s", idt, grant) + log.Debugf("%s + %s", idt, grant) } } if !n.Parent().IsNil() { - log.Debug("%s - parent: <%s>", idt, n.Parent().Name()) + log.Debugf("%s - parent: <%s>", idt, n.Parent().Name()) } if len(n.children) > 0 { - log.Debug("%s - children:", idt) + log.Debugf("%s - children:", idt) for _, c := range n.children { c.Dump(prefix, lvl+1) } @@ -482,7 +482,7 @@ func (p *policy) NewNumaNode(id idset.ID, parent Node) *numanode { // Dump (the NUMA-specific parts of) this node. func (n *numanode) dump(prefix string, level ...int) { - log.Debug("%s", indent(prefix, level...), n.id) + log.Debugf("%s", indent(prefix, level...), n.id) } // Get CPU supply available at this node. @@ -546,7 +546,7 @@ func (p *policy) NewL3CacheNode(id idset.ID, cpus cpuset.CPUSet, parent Node) *l // Dump (the L3 cache-specific parts of) this node. func (n *l3cachenode) dump(prefix string, level ...int) { - log.Debug("%s<%s, cpus: %s>", indent(prefix, level...), n.name, n.cpus) + log.Debugf("%s<%s, cpus: %s>", indent(prefix, level...), n.name, n.cpus) } // GetSupply returns CPU supply available at this node. @@ -625,7 +625,7 @@ func (p *policy) NewDieNode(id idset.ID, parent Node) *dienode { // Dump (the die-specific parts of) this node. func (n *dienode) dump(prefix string, level ...int) { - log.Debug("%s", indent(prefix, level...), n.syspkg.ID(), n.id) + log.Debugf("%s", indent(prefix, level...), n.syspkg.ID(), n.id) } // Get CPU supply available at this node. @@ -694,7 +694,7 @@ func (p *policy) NewSocketNode(id idset.ID, parent Node) *socketnode { // Dump (the socket-specific parts of) this node. func (n *socketnode) dump(prefix string, level ...int) { - log.Debug("%s", indent(prefix, level...), n.id) + log.Debugf("%s", indent(prefix, level...), n.id) } // Get CPU supply available at this node. @@ -756,7 +756,7 @@ func (p *policy) NewVirtualNode(name string, parent Node) *virtualnode { // Dump (the virtual-node specific parts of) this node. func (n *virtualnode) dump(prefix string, level ...int) { - log.Debug("%s", indent(prefix, level...), n.name) + log.Debugf("%s", indent(prefix, level...), n.name) } // Get CPU supply available at this node. diff --git a/cmd/plugins/topology-aware/policy/node_test.go b/cmd/plugins/topology-aware/policy/node_test.go index 35889adc0..bd1bf845a 100644 --- a/cmd/plugins/topology-aware/policy/node_test.go +++ b/cmd/plugins/topology-aware/policy/node_test.go @@ -85,13 +85,13 @@ func TestNodeLinkParent(t *testing.T) { child.LinkParent(parent) if child.parent != parent { - t.Error("child.parent not updated after LinkParent") + t.Errorf("child.parent not updated after LinkParent") } if child.depth != parent.depth+1 { t.Errorf("child.depth = %d, want %d", child.depth, parent.depth+1) } if len(parent.children) != 1 || parent.children[0] != child { - t.Error("child not added to parent.children after LinkParent") + t.Errorf("child not added to parent.children after LinkParent") } } @@ -106,7 +106,7 @@ func TestNodeAddChildren(t *testing.T) { t.Fatalf("expected 2 children, got %d", len(parent.children)) } if parent.children[0] != c1 || parent.children[1] != c2 { - t.Error("children not appended in order") + t.Errorf("children not appended in order") } } @@ -115,10 +115,10 @@ func TestNodeIsRootNode(t *testing.T) { child := &node{name: "child", id: 1, kind: SocketNode, parent: root} if !root.IsRootNode() { - t.Error("root.IsRootNode() = false, want true") + t.Errorf("root.IsRootNode() = false, want true") } if child.IsRootNode() { - t.Error("child.IsRootNode() = true, want false") + t.Errorf("child.IsRootNode() = true, want false") } } @@ -127,10 +127,10 @@ func TestNodeIsLeafNode(t *testing.T) { leaf := &node{name: "leaf", id: 99, kind: NumaNode, parent: root} if root.IsLeafNode() { - t.Error("root.IsLeafNode() = true, want false") + t.Errorf("root.IsLeafNode() = true, want false") } if !leaf.IsLeafNode() { - t.Error("leaf.IsLeafNode() = false, want true") + t.Errorf("leaf.IsLeafNode() = false, want true") } } @@ -156,7 +156,7 @@ func TestNodeParent(t *testing.T) { root, child1, _, _ := buildTestTree() if root.Parent() != nilnode { - t.Error("root.Parent() should be nilnode") + t.Errorf("root.Parent() should be nilnode") } if child1.Parent() != root { t.Errorf("child1.Parent() = %v, want root", child1.Parent()) @@ -171,7 +171,7 @@ func TestNodeChildren(t *testing.T) { t.Fatalf("root.Children() len = %d, want 2", len(children)) } if children[0] != child1 || children[1] != child2 { - t.Error("root.Children() returned unexpected nodes") + t.Errorf("root.Children() returned unexpected nodes") } } @@ -188,7 +188,7 @@ func TestNodeDepthFirstEarlyExit(t *testing.T) { }) if !done { - t.Error("DepthFirst should return true when the callback requests early exit") + t.Errorf("DepthFirst should return true when the callback requests early exit") } expected := []int{grandchild1.id, child1.id} if len(visited) != len(expected) { @@ -214,7 +214,7 @@ func TestNodeBreadthFirstEarlyExit(t *testing.T) { }) if !done { - t.Error("BreadthFirst should return true when the callback requests early exit") + t.Errorf("BreadthFirst should return true when the callback requests early exit") } expected := []int{root.id, child1.id} if len(visited) != len(expected) { @@ -231,9 +231,9 @@ func TestNodeIsSameNode(t *testing.T) { root, child1, _, _ := buildTestTree() if !root.IsSameNode(root) { - t.Error("node should be the same as itself") + t.Errorf("node should be the same as itself") } if root.IsSameNode(child1) { - t.Error("different nodes should not be the same") + t.Errorf("different nodes should not be the same") } } diff --git a/cmd/plugins/topology-aware/policy/pod-preferences.go b/cmd/plugins/topology-aware/policy/pod-preferences.go index bf752195a..cd1ee7642 100644 --- a/cmd/plugins/topology-aware/policy/pod-preferences.go +++ b/cmd/plugins/topology-aware/policy/pod-preferences.go @@ -150,12 +150,12 @@ func isolatedCPUsPreference(pod cache.Pod, container cache.Container) (bool, pre preference, err := strconv.ParseBool(value) if err != nil { - log.Error("invalid CPU isolation preference annotation (%q, %q): %v", + log.Errorf("invalid CPU isolation preference annotation (%q, %q): %v", key, value, err) return boolConfigPreference(opt.PreferIsolated) } - log.Debug("%s: effective CPU isolation preference %v", container.PrettyName(), preference) + log.Debugf("%s: effective CPU isolation preference %v", container.PrettyName(), preference) return preference, prefAnnotated } @@ -180,12 +180,12 @@ func sharedCPUsPreference(pod cache.Pod, container cache.Container) (bool, prefK preference, err := strconv.ParseBool(value) if err != nil { - log.Error("invalid shared CPU preference annotation (%q, %q): %v", + log.Errorf("invalid shared CPU preference annotation (%q, %q): %v", key, value, err) return boolConfigPreference(opt.PreferShared) } - log.Debug("%s: effective shared CPU preference %v", container.PrettyName(), preference) + log.Debugf("%s: effective shared CPU preference %v", container.PrettyName(), preference) return preference, prefAnnotated } @@ -198,25 +198,25 @@ func cpuPrioPreference(pod cache.Pod, container cache.Container, fallback cpuPri if !ok { prio := fallback - log.Debug("%s: implicit CPU priority preference %q", container.PrettyName(), prio) + log.Debugf("%s: implicit CPU priority preference %q", container.PrettyName(), prio) return prio } if value == "default" { prio := defaultPrio - log.Debug("%s: explicit default CPU priority preference %q", container.PrettyName(), prio) + log.Debugf("%s: explicit default CPU priority preference %q", container.PrettyName(), prio) return prio } prio, ok := cpuPrioByName[value] if !ok { - log.Error("%s: invalid CPU priority preference %q", container.PrettyName(), value) + log.Errorf("%s: invalid CPU priority preference %q", container.PrettyName(), value) prio := fallback - log.Debug("%s: implicit CPU priority preference %q", container.PrettyName(), prio) + log.Debugf("%s: implicit CPU priority preference %q", container.PrettyName(), prio) return prio } - log.Debug("%s: explicit CPU priority preference %q", container.PrettyName(), prio) + log.Debugf("%s: explicit CPU priority preference %q", container.PrettyName(), prio) return prio } @@ -243,17 +243,17 @@ func memoryTypePreference(pod cache.Pod, container cache.Container) memoryType { key := preferMemoryTypeKey value, ok := pod.GetEffectiveAnnotation(key, container.GetName()) if !ok { - log.Debug("pod %s has no memory preference annotations", pod.GetName()) + log.Debugf("pod %s has no memory preference annotations", pod.GetName()) return memoryUnspec } mtype, err := parseMemoryType(value) if err != nil { - log.Error("invalid memory type preference (%q, %q): %v", key, value, err) + log.Errorf("invalid memory type preference (%q, %q): %v", key, value, err) return memoryUnspec } - log.Debug("%s: effective memory type preference %v", container.PrettyName(), mtype) + log.Debugf("%s: effective memory type preference %v", container.PrettyName(), mtype) return mtype } @@ -263,7 +263,7 @@ func memoryTypePreference(pod cache.Pod, container cache.Container) memoryType { func schedulingClassPreference(ctr cache.Container) (*cfgapi.SchedulingClass, error) { name, ok := ctr.GetEffectiveAnnotation(keySchedulingClass) if ok { - log.Debug("%s: annotated scheduling preference %q", ctr.PrettyName(), name) + log.Debugf("%s: annotated scheduling preference %q", ctr.PrettyName(), name) sc := opt.GetSchedulingClass(name) if sc == nil { return nil, fmt.Errorf("unknown scheduling class %q", name) @@ -287,7 +287,7 @@ func coldStartPreference(pod cache.Pod, container cache.Container) (ColdStartPre preference := ColdStartPreference{} if err := yaml.Unmarshal([]byte(value), &preference); err != nil { - log.Error("failed to parse cold start preference (%q, %q): %v", + log.Errorf("failed to parse cold start preference (%q, %q): %v", key, value, err) return ColdStartPreference{}, policyError("invalid cold start preference %q: %v", value, err) @@ -298,7 +298,7 @@ func coldStartPreference(pod cache.Pod, container cache.Container) (ColdStartPre preference.Duration.String()) } - log.Debug("%s: effective cold start preference %v", + log.Debugf("%s: effective cold start preference %v", container.PrettyName(), preference.Duration.Duration.String()) return preference, nil @@ -339,7 +339,7 @@ func checkReservedCPUsAnnotations(c cache.Container) (bool, bool) { preference, err := strconv.ParseBool(hintSetting) if err != nil { - log.Error("failed to parse reserved CPU preference %s = '%s': %v", + log.Errorf("failed to parse reserved CPU preference %s = '%s': %v", keyReservedCPUsPreference, hintSetting, err) return false, false } @@ -521,12 +521,12 @@ func pickByHintsPreference(pod cache.Pod, container cache.Container) bool { pick, err := strconv.ParseBool(value) if err != nil { - log.Error("failed to parse pick resources by hints preference %s = '%s': %v", + log.Errorf("failed to parse pick resources by hints preference %s = '%s': %v", pickResourcesByHints, value, err) return false } - log.Debug("%s: effective pick resources by hints preference %v", + log.Debugf("%s: effective pick resources by hints preference %v", container.PrettyName(), pick) return pick diff --git a/cmd/plugins/topology-aware/policy/pools.go b/cmd/plugins/topology-aware/policy/pools.go index 8dc03891e..a6bbd613a 100644 --- a/cmd/plugins/topology-aware/policy/pools.go +++ b/cmd/plugins/topology-aware/policy/pools.go @@ -52,7 +52,7 @@ func (p *policy) buildPoolsByTopology() error { // is done by simply assigning all NUMA nodes without CPU locality to // the root pool). - log.Info("building pools by HW topology...") + log.Infof("building pools by HW topology...") p.nodes = make(map[string]Node) p.pools = make([]Node, 0) @@ -66,13 +66,13 @@ func (p *policy) buildPoolsByTopology() error { } func (p *policy) enumeratePools() { - log.Info("enumerating pools...") + log.Infof("enumerating pools...") id := 0 p.root.DepthFirst(func(n Node) (done bool) { n.(*node).id = id id++ - log.Info(" #%d: pool %s (depth %d)", n.NodeID(), n.Name(), n.RootDistance()) + log.Infof(" #%d: pool %s (depth %d)", n.NodeID(), n.Name(), n.RootDistance()) if p.depth < n.RootDistance() { p.depth = n.RootDistance() } @@ -94,13 +94,13 @@ func (p *policy) buildRootPool() { p.root = vroot root = vroot - log.Info("+ created pool %s", vroot.Name()) + log.Infof("+ created pool %s", vroot.Name()) cpus := p.sys.CPUSet() vroot.noderes, vroot.freeres = p.getCpuSupply(vroot, cpus) vroot.mem, vroot.pMem, vroot.hbm = p.getMemSupply(vroot, cpus) } else { - log.Info("- omitted virtual root pool (single socket HW)") + log.Infof("- omitted virtual root pool (single socket HW)") } for _, socketID := range p.sys.PackageIDs() { @@ -117,7 +117,7 @@ func (p *policy) buildSocketPool(socketID idset.ID, root Node) { p.root = socket } - log.Info("+ created pool %s", socket.Name()) + log.Infof("+ created pool %s", socket.Name()) cpus := p.sys.Package(socketID).CPUSet() socket.noderes, socket.freeres = p.getCpuSupply(socket, cpus) @@ -126,7 +126,7 @@ func (p *policy) buildSocketPool(socketID idset.ID, root Node) { dieIDs := p.sys.Package(socketID).DieIDs() omitDies := len(dieIDs) <= 1 if omitDies { - log.Info("- omitted die pools (only one die)") + log.Infof("- omitted die pools (only one die)") } dieIsCluster := true @@ -139,7 +139,7 @@ func (p *policy) buildSocketPool(socketID idset.ID, root Node) { } if dieIsCluster { omitDies = true - log.Info("- omitted die pools (dies are same as clusters)") + log.Infof("- omitted die pools (dies are same as clusters)") } if !omitDies { @@ -167,7 +167,7 @@ func (p *policy) buildDiePool(socketID, dieID idset.ID, socket Node) { p.nodes[die.Name()] = die die.depth = die.RootDistance() - log.Info("+ created pool %s", die.Name()) + log.Infof("+ created pool %s", die.Name()) cpus := p.sys.Package(socketID).DieCPUSet(dieID) die.noderes, die.freeres = p.getCpuSupply(die, cpus) @@ -197,7 +197,7 @@ func (p *policy) buildNumaNodePool(socketID, nodeID idset.ID, parent Node) { // Hence we omit this node, effectively folding its CPUs to parent, // making the CPUs less appealing for allocation than a sibling NUMA // node with some memory attached (and some CPU locality). - log.Info("- omitted pool %s%d (no memory attached)", "NUMA node #", nodeID) + log.Infof("- omitted pool %s%d (no memory attached)", "NUMA node #", nodeID) return } @@ -205,7 +205,7 @@ func (p *policy) buildNumaNodePool(socketID, nodeID idset.ID, parent Node) { p.nodes[node.Name()] = node node.depth = node.RootDistance() - log.Info("+ created pool %s", node.Name()) + log.Infof("+ created pool %s", node.Name()) cpus := p.sys.Node(nodeID).CPUSet() node.noderes, node.freeres = p.getCpuSupply(node, cpus) @@ -239,7 +239,7 @@ func (p *policy) buildL3CachePool(id idset.ID, cpus cpuset.CPUSet, parent Node) p.nodes[l3CacheNode.Name()] = l3CacheNode l3CacheNode.depth = l3CacheNode.RootDistance() - log.Info("+ created pool %s (cpus: %s)", l3CacheNode.Name(), cpus) + log.Infof("+ created pool %s (cpus: %s)", l3CacheNode.Name(), cpus) l3CacheNode.noderes, l3CacheNode.freeres = p.getCpuSupply(l3CacheNode, cpus) l3CacheNode.mem, l3CacheNode.pMem, l3CacheNode.hbm = p.getMemSupply(l3CacheNode, cpus) @@ -255,7 +255,7 @@ func (p *policy) getCpuSupply(node Node, cpus cpuset.CPUSet) (Supply, Supply) { s := newSupply(node, isolated, reserved, sharable, 0, 0) - log.Info(" %s CPU: %s", node.Name(), s.DumpCapacity()) + log.Infof(" %s CPU: %s", node.Name(), s.DumpCapacity()) return s, s.Clone() } @@ -264,37 +264,37 @@ func (p *policy) getMemSupply(node Node, cpus cpuset.CPUSet) (dram, pmem, hbm id if p.root == node { dram, pmem, hbm = p.splitMemsByType(p.getAllMems()) if dram.Size() > 0 { - log.Info(" %s all system DRAM: %s", node.Name(), dram) + log.Infof(" %s all system DRAM: %s", node.Name(), dram) } if pmem.Size() > 0 { - log.Info(" %s all system PMEM: %s", node.Name(), pmem) + log.Infof(" %s all system PMEM: %s", node.Name(), pmem) } if hbm.Size() > 0 { - log.Info(" %s all system HBM: %s", node.Name(), hbm) + log.Infof(" %s all system HBM: %s", node.Name(), hbm) } } else { mems := p.getMemsForCpus(cpus) dram, pmem, hbm = p.splitMemsByType(mems) if dram.Size() > 0 { - log.Info(" %s DRAM by CPU locality: %s", node.Name(), dram) + log.Infof(" %s DRAM by CPU locality: %s", node.Name(), dram) } if pmem.Size() > 0 { - log.Info(" %s PMEM by CPU locality: %s", node.Name(), pmem) + log.Infof(" %s PMEM by CPU locality: %s", node.Name(), pmem) } if hbm.Size() > 0 { - log.Info(" %s HBM by CPU locality: %s", node.Name(), hbm) + log.Infof(" %s HBM by CPU locality: %s", node.Name(), hbm) } dm, pm, hm := p.splitMemsByType(p.getClosestSpecialMem(mems)) if dm.Size() > 0 { - log.Info(" %s closest DRAM without CPU locality: %s", node.Name(), dm) + log.Infof(" %s closest DRAM without CPU locality: %s", node.Name(), dm) } if pm.Size() > 0 { - log.Info(" %s closest PMEM without CPU locality: %s", node.Name(), pm) + log.Infof(" %s closest PMEM without CPU locality: %s", node.Name(), pm) } if hm.Size() > 0 { - log.Info(" %s closest HBM without CPU locality: %s", node.Name(), hm) + log.Infof(" %s closest HBM without CPU locality: %s", node.Name(), hm) } dram.Add(dm.Members()...) pmem.Add(pm.Members()...) @@ -302,13 +302,13 @@ func (p *policy) getMemSupply(node Node, cpus cpuset.CPUSet) (dram, pmem, hbm id } if dram.Size() > 0 { - log.Info(" %s DRAM: %s", node.Name(), dram.String()) + log.Infof(" %s DRAM: %s", node.Name(), dram.String()) } if pmem.Size() > 0 { - log.Info(" %s PMEM: %s", node.Name(), pmem.String()) + log.Infof(" %s PMEM: %s", node.Name(), pmem.String()) } if hbm.Size() > 0 { - log.Info(" %s HBM: %s", node.Name(), hbm.String()) + log.Infof(" %s HBM: %s", node.Name(), hbm.String()) } return dram, pmem, hbm } @@ -399,7 +399,7 @@ func (p *policy) checkHWTopology() error { d1 := p.sys.NodeDistance(from, to) d2 := p.sys.NodeDistance(to, from) if d1 != d2 { - log.Error("asymmetric NUMA distance (#%d, #%d): %d != %d", + log.Errorf("asymmetric NUMA distance (#%d, #%d): %d != %d", from, to, d1, d2) return policyError("asymmetric NUMA distance (#%d, #%d): %d != %d", from, to, d1, d2) @@ -443,9 +443,9 @@ func (p *policy) allocatePool(container cache.Container, poolHint string) (Grant scores, pools := p.sortPoolsByScore(request, affinity) if log.DebugEnabled() { - log.Debug("* node fitting for %s", request) + log.Debugf("* node fitting for %s", request) for idx, n := range pools { - log.Debug(" - #%d: node %s, score %s, affinity: %d", + log.Debugf(" - #%d: node %s, score %s, affinity: %d", idx, n.Name(), scores[n.NodeID()], affinity[n.NodeID()]) } } @@ -458,13 +458,13 @@ func (p *policy) allocatePool(container cache.Container, poolHint string) (Grant if poolHint != "" { for idx, p := range pools { if p.Name() == poolHint { - log.Debug("* using hinted pool %q (#%d best fit)", poolHint, idx+1) + log.Debugf("* using hinted pool %q (#%d best fit)", poolHint, idx+1) pool = p break } } if pool == nil { - log.Debug("* cannot use hinted pool %q", poolHint) + log.Debugf("* cannot use hinted pool %q", poolHint) } } @@ -488,9 +488,9 @@ func (p *policy) allocatePool(container cache.Container, poolHint string) (Grant for id, z := range updates { g, ok := p.allocations.grants[id] if !ok { - log.Error("offer commit returned zone update %s for unknown container %s", z, id) + log.Errorf("offer commit returned zone update %s for unknown container %s", z, id) } else { - log.Info("updating memory allocation for %s to %s", g.GetContainer().PrettyName(), z) + log.Infof("updating memory allocation for %s to %s", g.GetContainer().PrettyName(), z) g.SetMemoryZone(z) if opt.PinMemory { g.GetContainer().SetCpusetMems(z.MemsetString()) @@ -498,7 +498,7 @@ func (p *policy) allocatePool(container cache.Container, poolHint string) (Grant } } - log.Debug("allocated req '%s' to memory zone %s", container.PrettyName(), + log.Debugf("allocated req '%s' to memory zone %s", container.PrettyName(), grant.GetMemoryZone()) p.allocations.grants[container.GetID()] = grant @@ -523,13 +523,13 @@ func (p *policy) setPreferredCpusetCpus(container cache.Container, allocated cpu hidingInfo = " (no hyperthreads to hide)" } } - log.Info("%s%s", info, hidingInfo) + log.Infof("%s%s", info, hidingInfo) container.SetCpusetCpus(allow.String()) } // Apply the result of allocation to the requesting container. func (p *policy) applyGrant(grant Grant) { - log.Info("* applying grant %s", grant) + log.Infof("* applying grant %s", grant) container := grant.GetContainer() cpuType := grant.CPUType() @@ -561,7 +561,7 @@ func (p *policy) applyGrant(grant Grant) { case cpuPreserve: // Will skip CPU pinning, may still pin memory. default: - log.Debug("unsupported granted cpuType %s", cpuType) + log.Debugf("unsupported granted cpuType %s", cpuType) return } @@ -572,14 +572,14 @@ func (p *policy) applyGrant(grant Grant) { if opt.PinCPU { if cpuType == cpuPreserve { - log.Info(" => preserving %s cpuset %s", container.PrettyName(), container.GetCpusetCpus()) + log.Infof(" => preserving %s cpuset %s", container.PrettyName(), container.GetCpusetCpus()) } else { if cpus.Size() > 0 { p.setPreferredCpusetCpus(container, cpus, fmt.Sprintf(" => pinning %s to (%s) cpuset %s", container.PrettyName(), kind, cpus)) } else { - log.Info(" => not pinning %s CPUs, cpuset is empty...", container.PrettyName()) + log.Infof(" => not pinning %s CPUs, cpuset is empty...", container.PrettyName()) container.SetCpusetCpus("") } } @@ -612,12 +612,12 @@ func (p *policy) applyGrant(grant Grant) { } if grant.MemoryType() == memoryPreserve { - log.Debug(" => preserving %s memory pinning %s", container.PrettyName(), container.GetCpusetMems()) + log.Debugf(" => preserving %s memory pinning %s", container.PrettyName(), container.GetCpusetMems()) } else { if mems != libmem.NodeMask(0) { - log.Debug(" => pinning %s to memory %s", container.PrettyName(), mems) + log.Debugf(" => pinning %s to memory %s", container.PrettyName(), mems) } else { - log.Debug(" => not pinning %s memory, memory set is empty...", container.PrettyName()) + log.Debugf(" => not pinning %s memory, memory set is empty...", container.PrettyName()) } container.SetCpusetMems(mems.MemsetString()) } @@ -633,15 +633,15 @@ func (p *policy) applyGrant(grant Grant) { // Release resources allocated by this grant. func (p *policy) releasePool(container cache.Container) (Grant, bool) { - log.Info("* releasing resources allocated to %s", container.PrettyName()) + log.Infof("* releasing resources allocated to %s", container.PrettyName()) grant, ok := p.allocations.grants[container.GetID()] if !ok { - log.Info(" => no grant found, nothing to do...") + log.Infof(" => no grant found, nothing to do...") return nil, false } - log.Info(" => releasing grant %s...", grant) + log.Infof(" => releasing grant %s...", grant) // Remove the grant from all supplys it uses. grant.Release() @@ -655,13 +655,13 @@ func (p *policy) releasePool(container cache.Container) (Grant, bool) { // Update shared allocations effected by agrant. func (p *policy) updateSharedAllocations(grant *Grant) { if grant != nil { - log.Info("* updating shared allocations affected by %s", (*grant).String()) + log.Infof("* updating shared allocations affected by %s", (*grant).String()) if (*grant).CPUType() == cpuReserved { - log.Info(" this grant uses reserved CPUs, does not affect shared allocations") + log.Infof(" this grant uses reserved CPUs, does not affect shared allocations") return } } else { - log.Info("* updating all shared allocations") + log.Infof("* updating all shared allocations") } for _, other := range p.allocations.grants { @@ -672,17 +672,17 @@ func (p *policy) updateSharedAllocations(grant *Grant) { } if other.CPUType() == cpuReserved { - log.Info(" => %s not affected (only reserved CPUs)...", other) + log.Infof(" => %s not affected (only reserved CPUs)...", other) continue } if other.CPUType() == cpuPreserve { - log.Info(" => %s not affected (preserving CPU pinning)", other) + log.Infof(" => %s not affected (preserving CPU pinning)", other) continue } if other.SharedPortion() == 0 && !other.ExclusiveCPUs().IsEmpty() { - log.Info(" => %s not affected (only exclusive CPUs)...", other) + log.Infof(" => %s not affected (only exclusive CPUs)...", other) continue } @@ -704,54 +704,54 @@ func (p *policy) updateSharedAllocations(grant *Grant) { // applySchedulingClass applies a scheduling class to a container. func (p *policy) applySchedulingClass(c cache.Container, sc *cfgapi.SchedulingClass) { - log.Debug(" - applying scheduling class %q to %s", sc.Name, c.PrettyName()) + log.Debugf(" - applying scheduling class %q to %s", sc.Name, c.PrettyName()) if sc.Policy != "" { if pol, err := sc.Policy.ToNRI(); err == nil { c.SetSchedulingPolicy(pol) - log.Debug(" - scheduling policy %q (%s)", sc.Policy, pol) + log.Debugf(" - scheduling policy %q (%s)", sc.Policy, pol) } else { - log.Debug(" - invalid scheduling policy %q in scheduling class %q: %v", sc.Policy, sc.Name, err) + log.Debugf(" - invalid scheduling policy %q in scheduling class %q: %v", sc.Policy, sc.Name, err) } } if sc.Priority != nil { c.SetSchedulingPriority(int32(*sc.Priority)) - log.Debug(" - scheduling priority %d", *sc.Priority) + log.Debugf(" - scheduling priority %d", *sc.Priority) } if len(sc.Flags) > 0 { if flags, err := sc.Flags.ToNRI(); err == nil { c.SetSchedulingFlags(flags) - log.Debug(" - scheduling flags %q", sc.Flags) + log.Debugf(" - scheduling flags %q", sc.Flags) } else { - log.Debug(" - invalid scheduling flags %q in scheduling class %q: %v", sc.Flags, sc.Name, err) + log.Debugf(" - invalid scheduling flags %q in scheduling class %q: %v", sc.Flags, sc.Name, err) } } if sc.Nice != nil { c.SetSchedulingNice(int32(*sc.Nice)) - log.Debug(" - nice value %d", *sc.Nice) + log.Debugf(" - nice value %d", *sc.Nice) } if sc.Runtime != nil { c.SetSchedulingRuntime(*sc.Runtime) - log.Debug(" - scheduling runtime %d", *sc.Runtime) + log.Debugf(" - scheduling runtime %d", *sc.Runtime) } if sc.Deadline != nil { c.SetSchedulingDeadline(*sc.Deadline) - log.Debug(" - scheduling deadline %d", *sc.Deadline) + log.Debugf(" - scheduling deadline %d", *sc.Deadline) } if sc.Period != nil { c.SetSchedulingPeriod(*sc.Period) - log.Debug(" - scheduling period %d", *sc.Period) + log.Debugf(" - scheduling period %d", *sc.Period) } if sc.IOClass != "" { if ioClass, err := sc.IOClass.ToNRI(); err == nil { c.SetSchedulingIOClass(ioClass) - log.Debug(" - IO class %q", sc.IOClass) + log.Debugf(" - IO class %q", sc.IOClass) } else { - log.Debug(" - invalid IO class %q in scheduling class %q: %v", sc.IOClass, sc.Name, err) + log.Debugf(" - invalid IO class %q in scheduling class %q: %v", sc.IOClass, sc.Name, err) } } if sc.IOPriority != nil { c.SetSchedulingIOPriority(int32(*sc.IOPriority)) - log.Debug(" - IO priority %d", *sc.IOPriority) + log.Debugf(" - IO priority %d", *sc.IOPriority) } } @@ -832,9 +832,9 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco a2 := affinityScore(affinity, node2) o1, o2 := score1.Offer(), score2.Offer() - log.Debug("comparing scores for %s and %s", node1.Name(), node2.Name()) - log.Debug(" %s: %s, affinity score %f", node1.Name(), score1.String(), a1) - log.Debug(" %s: %s, affinity score %f", node2.Name(), score2.String(), a2) + log.Debugf("comparing scores for %s and %s", node1.Name(), node2.Name()) + log.Debugf(" %s: %s, affinity score %f", node1.Name(), score1.String(), a1) + log.Debugf(" %s: %s, affinity score %f", node2.Name(), score2.String(), a2) // // Notes: @@ -871,32 +871,32 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco // a node with insufficient isolated or shared capacity loses switch { case cpuType == cpuNormal && ((isolated2 < 0 && isolated1 >= 0) || (shared2 < 0 && shared1 >= 0)): - log.Debug(" => %s loses, insufficent isolated or shared", node2.Name()) + log.Debugf(" => %s loses, insufficent isolated or shared", node2.Name()) return true case cpuType == cpuNormal && ((isolated1 < 0 && isolated2 >= 0) || (shared1 < 0 && shared2 >= 0)): - log.Debug(" => %s loses, insufficent isolated or shared", node1.Name()) + log.Debugf(" => %s loses, insufficent isolated or shared", node1.Name()) return false case cpuType == cpuReserved && reserved2 < 0 && reserved1 >= 0: - log.Debug(" => %s loses, insufficent reserved", node2.Name()) + log.Debugf(" => %s loses, insufficent reserved", node2.Name()) return true case cpuType == cpuReserved && reserved1 < 0 && reserved2 >= 0: - log.Debug(" => %s loses, insufficent reserved", node1.Name()) + log.Debugf(" => %s loses, insufficent reserved", node1.Name()) return false } - log.Debug(" - isolated/reserved/shared insufficiency is a TIE") + log.Debugf(" - isolated/reserved/shared insufficiency is a TIE") // higher affinity score wins if a1 > a2 { - log.Debug(" => %s loses on affinity", node2.Name()) + log.Debugf(" => %s loses on affinity", node2.Name()) return true } if a2 > a1 { - log.Debug(" => %s loses on affinity", node1.Name()) + log.Debugf(" => %s loses on affinity", node1.Name()) return false } - log.Debug(" - affinity is a TIE") + log.Debugf(" - affinity is a TIE") // better topology hint score wins hScores1 := score1.HintScores() @@ -906,41 +906,41 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco hs2, nz2 := combineHintScores(hScores2) if hs1 > hs2 { - log.Debug(" => %s WINS on hints", node1.Name()) + log.Debugf(" => %s WINS on hints", node1.Name()) return true } if hs2 > hs1 { - log.Debug(" => %s WINS on hints", node2.Name()) + log.Debugf(" => %s WINS on hints", node2.Name()) return false } - log.Debug(" - hints are a TIE") + log.Debugf(" - hints are a TIE") if hs1 == 0 { if nz1 > nz2 { - log.Debug(" => %s WINS on non-zero hints", node1.Name()) + log.Debugf(" => %s WINS on non-zero hints", node1.Name()) return true } if nz2 > nz1 { - log.Debug(" => %s WINS on non-zero hints", node2.Name()) + log.Debugf(" => %s WINS on non-zero hints", node2.Name()) return false } - log.Debug(" - non-zero hints are a TIE") + log.Debugf(" - non-zero hints are a TIE") } // for a tie, prefer lower nodes and smaller ids if hs1 == hs2 && nz1 == nz2 && (hs1 != 0 || nz1 != 0) { if depth1 > depth2 { - log.Debug(" => %s WINS as it is lower", node1.Name()) + log.Debugf(" => %s WINS as it is lower", node1.Name()) return true } if depth1 < depth2 { - log.Debug(" => %s WINS as it is lower", node2.Name()) + log.Debugf(" => %s WINS as it is lower", node2.Name()) return false } - log.Debug(" => %s WINS based on equal hint socres, lower id", + log.Debugf(" => %s WINS based on equal hint socres, lower id", map[bool]string{true: node1.Name(), false: node2.Name()}[id1 < id2]) return id1 < id2 @@ -950,39 +950,39 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco // better matching offer wins switch { case o1 != nil && o2 == nil: - log.Debug(" => %s loses on memory offer (failed offer)", node2.Name()) + log.Debugf(" => %s loses on memory offer (failed offer)", node2.Name()) return true case o1 == nil && o2 != nil: - log.Debug(" => %s loses on memory offer (failed offer)", node1.Name()) + log.Debugf(" => %s loses on memory offer (failed offer)", node1.Name()) return false case o1 == nil && o2 == nil: - log.Debug(" - memory offer is a TIE (both failed)") + log.Debugf(" - memory offer is a TIE (both failed)") default: m1, m2 := o1.NodeMask(), o2.NodeMask() t1, t2 := p.memZoneType(m1), p.memZoneType(m2) memType := request.MemoryType() if t1 == memType.TypeMask() && t2 != memType.TypeMask() { - log.Debug(" - %s loses on mis-matching type (%s != %s)", node2.Name(), t2, memType) + log.Debugf(" - %s loses on mis-matching type (%s != %s)", node2.Name(), t2, memType) return true } if t1 != memType.TypeMask() && t2 == memType.TypeMask() { - log.Debug(" - %s loses on mis-matching type (%s != %s)", node1.Name(), t1, memType) + log.Debugf(" - %s loses on mis-matching type (%s != %s)", node1.Name(), t1, memType) return false } - log.Debug(" - offer memory types are a tie (%s vs %s)", t1, t2) + log.Debugf(" - offer memory types are a tie (%s vs %s)", t1, t2) if req, lim := request.MemAmountToAllocate(), request.MemoryLimit(); req != lim { capa1, capa2 := p.poolZoneCapacity(node1, memType), p.poolZoneCapacity(node2, memType) if (lim != 0 && capa1 >= lim && capa2 < lim) || (lim == 0 && capa1 > capa2) { - log.Debug(" - %s loses on memory offer burstability", node2.Name()) + log.Debugf(" - %s loses on memory offer burstability", node2.Name()) return true } if (lim != 0 && capa1 < lim && capa2 >= lim) || (lim == 0 && capa2 > capa1) { - log.Debug(" - %s loses on memory offer burstability", node1.Name()) + log.Debugf(" - %s loses on memory offer burstability", node1.Name()) return false } - log.Debug(" - memory offers burstability are a TIE") + log.Debugf(" - memory offers burstability are a TIE") } } @@ -995,21 +995,21 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco r2 = b2 - limit ) - log.Debug(" - CPU burstability %s=%d, %s=%d, limit=%d", + log.Debugf(" - CPU burstability %s=%d, %s=%d, limit=%d", node1.Name(), b1, node2.Name(), b2, limit) if limit != unlimitedCPU { // prefer pool with enough burstable capacity switch { case r1 >= 0 && r2 < 0: - log.Debug(" - %s loses on insufficient CPU burstability (%d vs. %d for limit %d)", + log.Debugf(" - %s loses on insufficient CPU burstability (%d vs. %d for limit %d)", node2.Name(), b1, b2, limit) return true case r2 >= 0 && r1 < 0: - log.Debug(" - %s loses on insufficient CPU burstability", node1.Name()) + log.Debugf(" - %s loses on insufficient CPU burstability", node1.Name()) return false default: - log.Debug(" - CPU burstability is a TIE") + log.Debugf(" - CPU burstability is a TIE") } } else { // prefer a pool at configured topology level with more burstable capacity @@ -1019,43 +1019,43 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco target = node1.Policy().unlimitedBurstablePreference(ctr) ) - log.Debug(" - unlimited CPU burstable topology level: %s", target) - log.Debug(" - %s topology level: %s", node1.Name(), level1) - log.Debug(" - %s topology level: %s", node2.Name(), level2) + log.Debugf(" - unlimited CPU burstable topology level: %s", target) + log.Debugf(" - %s topology level: %s", node1.Name(), level1) + log.Debugf(" - %s topology level: %s", node2.Name(), level2) switch { case level1 == target && level2 != target: - log.Debug(" - %s WINS on burstability topology level (%s)", + log.Debugf(" - %s WINS on burstability topology level (%s)", node1.Name(), target) return true case level2 == target && level1 != target: - log.Debug(" - %s WINS on burstability topology level (%s)", + log.Debugf(" - %s WINS on burstability topology level (%s)", node2.Name(), target) return false case level1 == target && level2 == target: - log.Debug(" - burstability topology level (%s) is a TIE", target) + log.Debugf(" - burstability topology level (%s) is a TIE", target) if b1 > b2 { - log.Debug(" - %s WINS on more CPU burstability", node1.Name()) + log.Debugf(" - %s WINS on more CPU burstability", node1.Name()) return true } if b2 > b1 { - log.Debug(" - %s WINS on more CPU burstability", node2.Name()) + log.Debugf(" - %s WINS on more CPU burstability", node2.Name()) return false } - log.Debug(" - CPU burstability is a TIE") + log.Debugf(" - CPU burstability is a TIE") return id1 < id2 default: if level1.Value() > target.Value() && level2.Value() < target.Value() { - log.Debug(" - %s WINS on CPU burstability limit (%s, limit %s)", + log.Debugf(" - %s WINS on CPU burstability limit (%s, limit %s)", node1.Name(), level1, target) return true } if level2.Value() > target.Value() && level1.Value() < target.Value() { - log.Debug(" - %s WINS on CPU burstability limit (%s, limit %s)", + log.Debugf(" - %s WINS on CPU burstability limit (%s, limit %s)", node2.Name(), level2, target) return true } - log.Debug(" - CPU burstability limit is a TIE") + log.Debugf(" - CPU burstability limit is a TIE") return id1 < id2 } } @@ -1065,48 +1065,48 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco if o1 != nil && o2 != nil { m1, m2 := o1.NodeMask(), o2.NodeMask() if m1.Size() < m2.Size() { - log.Debug(" - %s loses on memory offer (%s less tight than %s)", + log.Debugf(" - %s loses on memory offer (%s less tight than %s)", node2.Name(), m2, m1) return true } if m2.Size() < m1.Size() { - log.Debug(" - %s loses on memory offer (%s less tight than %s)", + log.Debugf(" - %s loses on memory offer (%s less tight than %s)", node1.Name(), m1, m2) return false } if m2.Size() == m1.Size() { - log.Debug(" - memory offers are a TIE (%s vs. %s)", m1, m2) + log.Debugf(" - memory offers are a TIE (%s vs. %s)", m1, m2) } } // matching memory type wins if reqType := request.MemoryType(); reqType != memoryUnspec && reqType != memoryPreserve { if node1.HasMemoryType(reqType) && !node2.HasMemoryType(reqType) { - log.Debug(" => %s WINS on memory type", node1.Name()) + log.Debugf(" => %s WINS on memory type", node1.Name()) return true } if !node1.HasMemoryType(reqType) && node2.HasMemoryType(reqType) { - log.Debug(" => %s WINS on memory type", node2.Name()) + log.Debugf(" => %s WINS on memory type", node2.Name()) return false } - log.Debug(" - memory type is a TIE") + log.Debugf(" - memory type is a TIE") } // for low-prio and high-prio CPU preference, the only fulfilling node wins - log.Debug(" - preferred CPU priority is %s", request.CPUPrio()) + log.Debugf(" - preferred CPU priority is %s", request.CPUPrio()) switch request.CPUPrio() { case lowPrio: lp1, lp2 := score1.PrioCapacity(lowPrio), score2.PrioCapacity(lowPrio) - log.Debug(" - lp1 %d vs. lp2 %d", lp1, lp2) + log.Debugf(" - lp1 %d vs. lp2 %d", lp1, lp2) switch { case lp1 == lp2: - log.Debug(" - low-prio CPU capacity is a TIE") + log.Debugf(" - low-prio CPU capacity is a TIE") case lp1 >= 0 && lp2 < 0: - log.Debug(" => %s WINS based on low-prio CPU capacity", node1.Name()) + log.Debugf(" => %s WINS based on low-prio CPU capacity", node1.Name()) return true case lp1 < 0 && lp2 >= 0: - log.Debug(" => %s WINS based on low-prio CPU capacity", node2.Name()) + log.Debugf(" => %s WINS based on low-prio CPU capacity", node2.Name()) return false } @@ -1114,27 +1114,27 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco hp1, hp2 := score1.PrioCapacity(highPrio), score2.PrioCapacity(highPrio) switch { case hp1 == hp2: - log.Debug(" - HighPrio CPU capacity is a TIE") + log.Debugf(" - HighPrio CPU capacity is a TIE") case hp1 >= 0 && hp2 < 0: - log.Debug(" => %s WINS based on high-prio CPU capacity", node1.Name()) + log.Debugf(" => %s WINS based on high-prio CPU capacity", node1.Name()) return true case hp1 < 0 && hp2 >= 0: - log.Debug(" => %s WINS based on high-prio CPU capacity", node2.Name()) + log.Debugf(" => %s WINS based on high-prio CPU capacity", node2.Name()) return false } } // a lower node wins if depth1 > depth2 { - log.Debug(" => %s WINS on depth", node1.Name()) + log.Debugf(" => %s WINS on depth", node1.Name()) return true } if depth1 < depth2 { - log.Debug(" => %s WINS on depth", node2.Name()) + log.Debugf(" => %s WINS on depth", node2.Name()) return false } - log.Debug(" - depth is a TIE") + log.Debugf(" - depth is a TIE") if request.CPUType() == cpuReserved { // if requesting reserved CPUs, more reserved @@ -1148,7 +1148,7 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco if reserved2/(score2.Colocated()+1) > reserved1/(score1.Colocated()+1) { return false } - log.Debug(" - reserved capacity is a TIE") + log.Debugf(" - reserved capacity is a TIE") } else if request.CPUType() == cpuNormal { // more isolated capacity wins if request.Isolate() && (isolated1 > 0 || isolated2 > 0) { @@ -1159,24 +1159,24 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco return false } - log.Debug(" => %s WINS based on equal isolated capacity, lower id", + log.Debugf(" => %s WINS based on equal isolated capacity, lower id", map[bool]string{true: node1.Name(), false: node2.Name()}[id1 < id2]) return id1 < id2 } // for normal-prio CPU preference, the only fulfilling node wins - log.Debug(" - preferred CPU priority is %s", request.CPUPrio()) + log.Debugf(" - preferred CPU priority is %s", request.CPUPrio()) if request.CPUPrio() == normalPrio { np1, np2 := score1.PrioCapacity(normalPrio), score2.PrioCapacity(normalPrio) switch { case np1 == np2: - log.Debug(" - normal-prio CPU capacity is a TIE") + log.Debugf(" - normal-prio CPU capacity is a TIE") case np1 >= 0 && np2 < 0: - log.Debug(" => %s WINS based on normal-prio CPU capacity", node1.Name()) + log.Debugf(" => %s WINS based on normal-prio CPU capacity", node1.Name()) return true case np1 < 0 && np2 >= 0: - log.Debug(" => %s WINS based on normal-prio capacity", node2.Name()) + log.Debugf(" => %s WINS based on normal-prio capacity", node2.Name()) return false } } @@ -1184,15 +1184,15 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco // more sliceable shared capacity wins if request.FullCPUs() > 0 && (shared1 > 0 || shared2 > 0) { if shared1 > shared2 { - log.Debug(" => %s WINS on more sliceable capacity", node1.Name()) + log.Debugf(" => %s WINS on more sliceable capacity", node1.Name()) return true } if shared2 > shared1 { - log.Debug(" => %s WINS on more sliceable capacity", node2.Name()) + log.Debugf(" => %s WINS on more sliceable capacity", node2.Name()) return false } - log.Debug(" => %s WINS based on equal sliceable capacity, lower id", + log.Debugf(" => %s WINS based on equal sliceable capacity, lower id", map[bool]string{true: node1.Name(), false: node2.Name()}[id1 < id2]) return id1 < id2 @@ -1200,29 +1200,29 @@ func (p *policy) compareScores(request Request, pools []Node, scores map[int]Sco // fewer colocated containers win if score1.Colocated() < score2.Colocated() { - log.Debug(" => %s WINS on colocation score", node1.Name()) + log.Debugf(" => %s WINS on colocation score", node1.Name()) return true } if score2.Colocated() < score1.Colocated() { - log.Debug(" => %s WINS on colocation score", node2.Name()) + log.Debugf(" => %s WINS on colocation score", node2.Name()) return false } - log.Debug(" - colocation score is a TIE") + log.Debugf(" - colocation score is a TIE") // more shared capacity wins if shared1 > shared2 { - log.Debug(" => %s WINS on more shared capacity", node1.Name()) + log.Debugf(" => %s WINS on more shared capacity", node1.Name()) return true } if shared2 > shared1 { - log.Debug(" => %s WINS on more shared capacity", node2.Name()) + log.Debugf(" => %s WINS on more shared capacity", node2.Name()) return false } } // lower id wins - log.Debug(" => %s WINS based on lower id", + log.Debugf(" => %s WINS based on lower id", map[bool]string{true: node1.Name(), false: node2.Name()}[id1 < id2]) return id1 < id2 diff --git a/cmd/plugins/topology-aware/policy/resources.go b/cmd/plugins/topology-aware/policy/resources.go index 40513aa7d..c0ac52ee4 100644 --- a/cmd/plugins/topology-aware/policy/resources.go +++ b/cmd/plugins/topology-aware/policy/resources.go @@ -410,17 +410,17 @@ func (cs *supply) AllocateCPU(r Request) (Grant, error) { cpuType := cr.cpuType if cpuType == cpuReserved && full > 0 { - log.Warn("exclusive reserved CPUs not supported, allocating %d full CPUs as fractions", full) + log.Warnf("exclusive reserved CPUs not supported, allocating %d full CPUs as fractions", full) fraction += full * 1000 full = 0 } if cpuType == cpuReserved && fraction > 0 && cs.AllocatableReservedCPU() < fraction { - log.Warn("possible misconfiguration of reserved resources:") - log.Warn(" %s: allocatable %s", cs.GetNode().Name(), cs.DumpAllocatable()) - log.Warn(" %s: needs %d reserved, only %d available", + log.Warnf("possible misconfiguration of reserved resources:") + log.Warnf(" %s: allocatable %s", cs.GetNode().Name(), cs.DumpAllocatable()) + log.Warnf(" %s: needs %d reserved, only %d available", cr.GetContainer().PrettyName(), fraction, cs.AllocatableReservedCPU()) - log.Warn(" falling back to using normal unreserved CPUs instead...") + log.Warnf(" falling back to using normal unreserved CPUs instead...") cpuType = cpuNormal } @@ -449,7 +449,7 @@ func (cs *supply) AllocateCPU(r Request) (Grant, error) { cs.node.Name(), full, cs.SharableCPUs(), err) } - log.Debug("%s: sliceable cpuset is %s", cs.node.Name(), sliceable) + log.Debugf("%s: sliceable cpuset is %s", cs.node.Name(), sliceable) if cr.PickByHints() { exclusive, ok = cs.takeCPUsByHints(&sliceable, cr) if !ok { @@ -744,7 +744,7 @@ func newRequest(container cache.Container, types libmem.TypeMask) Request { req, lim, mtype := memoryAllocationPreference(pod, container) coldStart := time.Duration(0) - log.Debug("%s: CPU preferences: cpuType=%s, full=%v, fraction=%v, isolate=%v, prio=%v", + log.Debugf("%s: CPU preferences: cpuType=%s, full=%v, fraction=%v, isolate=%v, prio=%v", container.PrettyName(), cpuType, full, fraction, isolate, prio) if mtype == memoryUnspec { @@ -757,13 +757,13 @@ func newRequest(container cache.Container, types libmem.TypeMask) Request { if coldStartOff { if mtype == memoryPMEM { mtype |= memoryDRAM - log.Error("%s: coldstart disabled (movable non-DRAM memory zones present)", + log.Errorf("%s: coldstart disabled (movable non-DRAM memory zones present)", container.PrettyName()) } } else { pref, err := coldStartPreference(pod, container) if err != nil { - log.Error("failed to parse coldstart preference") + log.Errorf("failed to parse coldstart preference") } else { coldStart = time.Duration(pref.Duration.Duration) if coldStart > 0 { @@ -1015,7 +1015,7 @@ func (cs *supply) GetScore(req Request) Score { score.hints = make(map[string]float64, len(hints)) for provider, hint := range cr.container.GetTopologyHints() { - log.Debug(" - evaluating topology hint %s", hint) + log.Debugf(" - evaluating topology hint %s", hint) score.hints[provider] = cs.node.HintScore(hint) } @@ -1040,9 +1040,9 @@ func (cs *supply) GetScore(req Request) Score { } if err != nil { - log.Error("failed to get offer for request %s: %v", req, err) + log.Errorf("failed to get offer for request %s: %v", req, err) } else { - log.Debug("got node %s offer for request %s: %s", node.Name(), req, o.NodeMask()) + log.Debugf("got node %s offer for request %s: %s", node.Name(), req, o.NodeMask()) score.offer = o } @@ -1075,14 +1075,14 @@ func (cs *supply) AllocatableSharedCPU(quiet ...bool) int { // none of them gets overcommitted as the result of fulfilling this request. shared := 1000*cs.sharable.Size() - cs.node.GrantedSharedCPU() if verbose { - log.Debug("%s: unadjusted free shared CPU: %dm", cs.node.Name(), shared) + log.Debugf("%s: unadjusted free shared CPU: %dm", cs.node.Name(), shared) } for node := cs.node.Parent(); !node.IsNil(); node = node.Parent() { pSupply := node.FreeSupply() pShared := 1000*pSupply.SharableCPUs().Size() - pSupply.GetNode().GrantedSharedCPU() if pShared < shared { if verbose { - log.Debug("%s: capping free shared CPU (%dm -> %dm) to avoid overcommit of %s", + log.Debugf("%s: capping free shared CPU (%dm -> %dm) to avoid overcommit of %s", cs.node.Name(), shared, pShared, node.Name()) } shared = pShared @@ -1090,7 +1090,7 @@ func (cs *supply) AllocatableSharedCPU(quiet ...bool) int { } if verbose { - log.Debug("%s: ancestor-adjusted free shared CPU: %dm", cs.node.Name(), shared) + log.Debugf("%s: ancestor-adjusted free shared CPU: %dm", cs.node.Name(), shared) } // If there are BestEffort or 0 CPU request Burstable containers in the node @@ -1109,7 +1109,7 @@ func (cs *supply) AllocatableSharedCPU(quiet ...bool) int { if hasZeroCpuReqs { shared-- if verbose { - log.Debug("%s: 0 CPU req-adjusted free shared CPU: %dm", + log.Debugf("%s: 0 CPU req-adjusted free shared CPU: %dm", cs.node.Name(), shared) } } @@ -1386,7 +1386,7 @@ func (cg *grant) Release() { cg.GetCPUNode().FreeSupply().ReleaseCPU(cg) err := cg.node.Policy().releaseMem(cg.container.GetID()) if err != nil { - log.Error("releasing memory for %s failed: %v", cg.container.PrettyName(), err) + log.Errorf("releasing memory for %s failed: %v", cg.container.PrettyName(), err) } cg.StopTimer() } @@ -1405,9 +1405,9 @@ func (cg *grant) ReallocMemory(types libmem.TypeMask) error { for id, z := range updates { g, ok := cg.node.Policy().allocations.grants[id] if !ok { - log.Error("offer commit returned zone update %s for unknown container %s", z, id) + log.Errorf("offer commit returned zone update %s for unknown container %s", z, id) } else { - log.Info("updating memory allocation for %s to %s", g.GetContainer().PrettyName(), z) + log.Infof("updating memory allocation for %s to %s", g.GetContainer().PrettyName(), z) g.SetMemoryZone(z) if opt.PinMemory { g.GetContainer().SetCpusetMems(z.MemsetString()) diff --git a/cmd/plugins/topology-aware/policy/topology-aware-policy.go b/cmd/plugins/topology-aware/policy/topology-aware-policy.go index 2b23471d8..becdac4fb 100644 --- a/cmd/plugins/topology-aware/policy/topology-aware-policy.go +++ b/cmd/plugins/topology-aware/policy/topology-aware-policy.go @@ -113,7 +113,7 @@ func (p *policy) Setup(opts *policyapi.BackendOptions) error { return policyError("failed to initialize %s policy: %w", PolicyName, err) } - log.Info("***** default CPU priority is %s", defaultPrio) + log.Infof("***** default CPU priority is %s", defaultPrio) return nil } @@ -155,7 +155,7 @@ func (p *policy) Start() error { // Sync synchronizes the state of this policy. func (p *policy) Sync(add []cache.Container, del []cache.Container) error { - log.Debug("synchronizing state...") + log.Debugf("synchronizing state...") for _, c := range del { if err := p.ReleaseResources(c); err != nil { log.Warnf("failed to release resources for %s: %v", c.PrettyName(), err) @@ -183,7 +183,7 @@ func (p *policy) checkAllocations(format string, args ...interface{}) { ) for _, g := range p.allocations.grants { - log.Debug("%s %s (%s)", prefix, g, g.GetContainer().GetID()) + log.Debugf("%s %s (%s)", prefix, g, g.GetContainer().GetID()) full := g.ExclusiveCPUs().Size() part := g.CPUPortion() cpuExcl += full @@ -193,7 +193,7 @@ func (p *policy) checkAllocations(format string, args ...interface{}) { _, ok := p.cache.LookupContainer(g.GetContainer().GetID()) if !ok { - log.Error("%s %s STALE container among allocations, not found in cache", prefix, g) + log.Errorf("%s %s STALE container among allocations, not found in cache", prefix, g) } key := g.GetContainer().PrettyName() @@ -210,20 +210,20 @@ func (p *policy) checkAllocations(format string, args ...interface{}) { } for key, grants := range dup { - log.Error("%s DUPLICATE allocation entries for container %s", prefix, key) + log.Errorf("%s DUPLICATE allocation entries for container %s", prefix, key) for _, g := range grants { - log.Error("%s %s (%s)", prefix, g, g.GetContainer().GetID()) + log.Errorf("%s %s (%s)", prefix, g, g.GetContainer().GetID()) } } - log.Info("%s total CPU granted: %dm (%d exclusive + %dm shared), total memory granted: %s", + log.Infof("%s total CPU granted: %dm (%d exclusive + %dm shared), total memory granted: %s", prefix, 1000*cpuExcl+cpuPart, cpuExcl, cpuPart, prettyMem(mem)) } // AllocateResources is a resource allocation request for this policy. func (p *policy) AllocateResources(container cache.Container) error { - log.Debug("allocating resources for %s (%s)...", container.PrettyName(), container.GetID()) + log.Debugf("allocating resources for %s (%s)...", container.PrettyName(), container.GetID()) err := p.allocateResources(container, "") if err != nil { @@ -252,7 +252,7 @@ func (p *policy) allocateResources(container cache.Container, poolHint string) e // ReleaseResources is a resource release request for this policy. func (p *policy) ReleaseResources(container cache.Container) error { - log.Debug("releasing resources for %s (%s)...", container.PrettyName(), container.GetID()) + log.Debugf("releasing resources for %s (%s)...", container.PrettyName(), container.GetID()) if grant, found := p.releasePool(container); found { p.updateSharedAllocations(&grant) @@ -268,7 +268,7 @@ func (p *policy) ReleaseResources(container cache.Container) error { // UpdateResources is a resource allocation update request for this policy. func (p *policy) UpdateResources(container cache.Container) error { - log.Debug("updating (reallocating) container %s...", container.PrettyName()) + log.Debugf("updating (reallocating) container %s...", container.PrettyName()) grant, found := p.releasePool(container) if !found { @@ -293,7 +293,7 @@ func (p *policy) UpdateResources(container cache.Container) error { // HandleEvent handles policy-specific events. func (p *policy) HandleEvent(e *events.Policy) (bool, error) { - log.Debug("received policy event %s.%s with data %v...", e.Source, e.Type, e.Data) + log.Debugf("received policy event %s.%s with data %v...", e.Source, e.Type, e.Data) switch e.Type { case events.ContainerStarted: @@ -302,7 +302,7 @@ func (p *policy) HandleEvent(e *events.Policy) (bool, error) { return false, policyError("%s event: expecting cache.Container Data, got %T", e.Type, e.Data) } - log.Info("triggering coldstart period (if necessary) for %s", c.PrettyName()) + log.Infof("triggering coldstart period (if necessary) for %s", c.PrettyName()) return false, p.triggerColdStart(c) case ColdStartDone: id, ok := e.Data.(string) @@ -315,7 +315,7 @@ func (p *policy) HandleEvent(e *events.Policy) (bool, error) { // TODO: This is probably a race condition. Should we return nil error here? return false, policyError("%s event: failed to lookup container %s", id) } - log.Info("finishing coldstart period for %s", c.PrettyName()) + log.Infof("finishing coldstart period for %s", c.PrettyName()) return p.finishColdStart(c) } return false, nil @@ -439,7 +439,7 @@ func (p *policy) ExportResourceData(c cache.Container) map[string]string { func (p *policy) reallocateResources(containers []cache.Container, pools map[string]string) error { errs := []error{} - log.Info("reallocating resources...") + log.Infof("reallocating resources...") cache.SortContainers(containers) @@ -447,7 +447,7 @@ func (p *policy) reallocateResources(containers []cache.Container, pools map[str p.releasePool(c) } for _, c := range containers { - log.Debug("reallocating resources for %s (%s)...", c.PrettyName(), c.GetID()) + log.Debugf("reallocating resources for %s (%s)...", c.PrettyName(), c.GetID()) grant, err := p.allocatePool(c, pools[c.GetID()]) if err != nil { @@ -499,7 +499,7 @@ func (p *policy) Reconfigure(newCfg interface{}) error { } } - log.Warn("updating existing allocations...") + log.Warnf("updating existing allocations...") if err := p.restoreAllocations(&allocations); err != nil { *p = savedPolicy opt = p.cfg @@ -639,7 +639,7 @@ func (p *policy) findExistingTopologyLevel(level cfgapi.CPUTopologyLevel) cfgapi return l } if l.Value() < level.Value() { - log.Warn("no pool of kind %q (%q), using %q instead", + log.Warnf("no pool of kind %q (%q), using %q instead", level, NodeKindForTopologyLevel(level), l) return l } @@ -667,7 +667,7 @@ func (p *policy) checkColdstartOff() { if node.GetMemoryType() == system.MemoryTypePMEM { if !node.HasNormalMemory() { coldStartOff = true - log.Error("coldstart forced off: NUMA node #%d does not have normal memory", id) + log.Errorf("coldstart forced off: NUMA node #%d does not have normal memory", id) return } } diff --git a/cmd/resource-annotator/webhook.go b/cmd/resource-annotator/webhook.go index 8577c87fe..6ad04b346 100644 --- a/cmd/resource-annotator/webhook.go +++ b/cmd/resource-annotator/webhook.go @@ -118,7 +118,7 @@ func (w *Webhook) processRequest(r *http.Request) (*admv1.AdmissionReview, error switch t := r.Header.Get("Content-Type"); t { case contentTypeJSON: case contentTypeProbe: - w.Debug("received liveness probe") + w.Debugf("received liveness probe") rpl.Response = probeResponse() return rpl, nil default: diff --git a/pkg/agent/agent.go b/pkg/agent/agent.go index 9f63cbae9..d001043a3 100644 --- a/pkg/agent/agent.go +++ b/pkg/agent/agent.go @@ -280,7 +280,7 @@ func getAgentConfig(newConfig metav1.Object) *cfgapi.AgentConfig { func (a *Agent) configure(newConfig metav1.Object) { if a.hasLocalConfig() { - log.Warn("running with local configuration, skipping client setup...") + log.Warnf("running with local configuration, skipping client setup...") return } @@ -289,21 +289,21 @@ func (a *Agent) configure(newConfig metav1.Object) { // Failure to create a client is not a fatal error. switch { case cfg.NodeResourceTopology && a.nrtCli == nil: - log.Info("enabling NRT client") + log.Infof("enabling NRT client") cfg, err := a.getRESTConfig() if err != nil { - log.Error("failed to setup NRT client: %w", err) + log.Errorf("failed to setup NRT client: %w", err) break } cli, err := nrtapi.NewForConfigAndClient(cfg, a.httpCli) if err != nil { - log.Error("failed to setup NRT client: %w", err) + log.Errorf("failed to setup NRT client: %w", err) break } a.nrtCli = cli case !cfg.NodeResourceTopology && a.nrtCli != nil: - log.Info("disabling NRT client") + log.Infof("disabling NRT client") a.nrtCli = nil } @@ -311,16 +311,16 @@ func (a *Agent) configure(newConfig metav1.Object) { // Failure to create a client is not a fatal error. switch { case cfg.PodResourceAPI && a.podResCli == nil: - log.Info("enabling PodResourceAPI client") + log.Infof("enabling PodResourceAPI client") cli, err := podresapi.NewClient() if err != nil { - log.Error("failed to setup PodResourceAPI client: %v", err) + log.Errorf("failed to setup PodResourceAPI client: %v", err) break } a.podResCli = cli case !cfg.PodResourceAPI && a.podResCli != nil: - log.Info("disabling PodResourceAPI client") + log.Infof("disabling PodResourceAPI client") a.podResCli.Close() a.podResCli = nil } @@ -332,14 +332,14 @@ func (a *Agent) hasLocalConfig() bool { func (a *Agent) setupClients() error { if a.hasLocalConfig() { - log.Warn("running with local configuration, skipping cluster access client setup...") + log.Warnf("running with local configuration, skipping cluster access client setup...") return nil } // Create HTTP/REST client and K8s client on initial startup. Any failure // to create these is a failure start up. if a.httpCli == nil { - log.Info("setting up HTTP/REST client...") + log.Infof("setting up HTTP/REST client...") restCfg, err := a.getRESTConfig() if err != nil { return err @@ -350,7 +350,7 @@ func (a *Agent) setupClients() error { return fmt.Errorf("failed to setup kubernetes HTTP client: %w", err) } - log.Info("setting up K8s client...") + log.Infof("setting up K8s client...") a.k8sCli, err = k8sclient.NewForConfigAndClient(restCfg, a.httpCli) if err != nil { a.cleanupClients() @@ -522,21 +522,21 @@ func (a *Agent) updateNodeConfig(obj runtime.Object) { if obj != nil { o, ok := obj.(metav1.Object) if !ok { - log.Error("can't handle object %T, not meta/v1.Object, ignoring it", obj) + log.Errorf("can't handle object %T, not meta/v1.Object, ignoring it", obj) return } cfg = o } if sameConfigVersion(cfg, a.nodeCfg) { - log.Debug("ignoring duplicate node-specific config update") + log.Debugf("ignoring duplicate node-specific config update") return } if cfg == nil { - log.Info("node-specific config deleted") + log.Infof("node-specific config deleted") } else { - log.Info("node-specific config updated") + log.Infof("node-specific config updated") } a.nodeCfg = cfg @@ -561,21 +561,21 @@ func (a *Agent) updateGroupConfig(obj runtime.Object) { if obj != nil { o, ok := obj.(metav1.Object) if !ok { - log.Error("can't handle object %T, not meta/v1.Object, ignoring it", obj) + log.Errorf("can't handle object %T, not meta/v1.Object, ignoring it", obj) return } cfg = o } if sameConfigVersion(cfg, a.groupCfg) { - log.Debug("ignoring duplicate group-specific config update") + log.Debugf("ignoring duplicate group-specific config update") return } if cfg == nil { - log.Info("group-specific config deleted") + log.Infof("group-specific config deleted") } else { - log.Info("group-specific config updated") + log.Infof("group-specific config updated") } // diff --git a/pkg/agent/node-resource-topology.go b/pkg/agent/node-resource-topology.go index b3cb48f2e..f1aa39e44 100644 --- a/pkg/agent/node-resource-topology.go +++ b/pkg/agent/node-resource-topology.go @@ -35,7 +35,7 @@ func (a *Agent) UpdateNrtCR(policy string, zones []*policyapi.TopologyZone) erro return fmt.Errorf("no node resource topology client, can't update CR") } - log.Info("updating node resource topology CR") + log.Infof("updating node resource topology CR") // To minimize the risk of an NRI request timeout (and the plugin getting // kicked out) we do the update asynchronously. We can rework this to use @@ -63,7 +63,7 @@ func (a *Agent) updateNrtCR(policy string, zones []*policyapi.TopologyZone) erro if err != nil { cr = nil if !errors.IsNotFound(err) { - log.Warn("failed to look up current node resource topology CR: %v", err) + log.Warnf("failed to look up current node resource topology CR: %v", err) } } diff --git a/pkg/agent/pod-resource-api.go b/pkg/agent/pod-resource-api.go index d5d497ef5..720257e12 100644 --- a/pkg/agent/pod-resource-api.go +++ b/pkg/agent/pod-resource-api.go @@ -41,7 +41,7 @@ func (a *Agent) GoGetPodResources(ns, pod string, timeout time.Duration) <-chan defer close(ch) p, err := a.GetPodResources(ns, pod, timeout) if err != nil { - log.Error("failed to get pod resources for %s/%s: %v", ns, pod, err) + log.Errorf("failed to get pod resources for %s/%s: %v", ns, pod, err) return } ch <- p @@ -70,7 +70,7 @@ func (a *Agent) GoListPodResources(timeout time.Duration) <-chan *podresapi.PodR defer close(ch) l, err := a.ListPodResources(timeout) if err != nil { - log.Error("failed to list pod resources: %v", err) + log.Errorf("failed to list pod resources: %v", err) return } ch <- l diff --git a/pkg/agent/podresapi/resources.go b/pkg/agent/podresapi/resources.go index a60469778..4fe242493 100644 --- a/pkg/agent/podresapi/resources.go +++ b/pkg/agent/podresapi/resources.go @@ -141,7 +141,7 @@ func (r *ContainerResources) GetDeviceTopologyHints(checkDenied func(string) boo name := HintProvider + dev.GetResourceName() if checkDenied(name) { - log.Info("filtering hints for disallowed device %s", name) + log.Infof("filtering hints for disallowed device %s", name) continue } diff --git a/pkg/agent/watch/file.go b/pkg/agent/watch/file.go index 7afc117b7..a7a2fea98 100644 --- a/pkg/agent/watch/file.go +++ b/pkg/agent/watch/file.go @@ -132,7 +132,7 @@ func (w *FileWatch) run() error { continue } - log.Debug("got %v event for %s", e.Op, e.Name) + log.Debugf("got %v event for %s", e.Op, e.Name) switch { case (e.Op & fsnotify.Create) != 0: @@ -167,7 +167,7 @@ func (w *FileWatch) sendEvent(t EventType, obj runtime.Object) { select { case w.resultC <- Event{Type: t, Object: obj}: default: - log.Warn("failed to deliver file watch event (%v)", t) + log.Warnf("failed to deliver file watch event (%v)", t) } } diff --git a/pkg/agent/watch/object.go b/pkg/agent/watch/object.go index e7eb9e4a2..bd5a3bc8a 100644 --- a/pkg/agent/watch/object.go +++ b/pkg/agent/watch/object.go @@ -106,7 +106,7 @@ func (w *ObjectWatch) run() error { case e, ok := <-w.eventChan(): if !ok { - log.Debug("watch %s expired", w.watchname()) + log.Debugf("watch %s expired", w.watchname()) w.reopen() continue } @@ -154,7 +154,7 @@ func (w *ObjectWatch) reopen() { if err := w.open(); err != nil { w.scheduleReopen() } else { - log.Debug("watch %s reopened", w.watchname()) + log.Debugf("watch %s reopened", w.watchname()) w.markRunning() } } @@ -182,14 +182,14 @@ func (w *ObjectWatch) watchname() string { func (w *ObjectWatch) markFailing() { if !w.failing { - log.Error("watch %s is now failing", w.watchname()) + log.Errorf("watch %s is now failing", w.watchname()) w.failing = true } } func (w *ObjectWatch) markRunning() { if w.failing { - log.Info("watch %s is now running again", w.watchname()) + log.Infof("watch %s is now running again", w.watchname()) w.failing = false } } diff --git a/pkg/apis/resmgr/v1alpha1/expression.go b/pkg/apis/resmgr/v1alpha1/expression.go index b7fbb0466..e737d9a5d 100644 --- a/pkg/apis/resmgr/v1alpha1/expression.go +++ b/pkg/apis/resmgr/v1alpha1/expression.go @@ -116,7 +116,7 @@ VALIDATE_KEYS: // Evaluate evaluates an expression against a container. func (e *Expression) Evaluate(subject Evaluable) bool { - log.Debug("evaluating %q @ %s...", *e, subject) + log.Debugf("evaluating %q @ %s...", *e, subject) if e.Op == AlwaysTrue { return true @@ -168,7 +168,7 @@ func (e *Expression) Evaluate(subject Evaluable) bool { result = !ok } - log.Debug("%q @ %s => %v", *e, subject, result) + log.Debugf("%q @ %s => %v", *e, subject, result) return result } @@ -180,7 +180,7 @@ func (e *Expression) String() string { // KeyValue extracts the value of the expression in the scope of the given subject. func KeyValue(key string, subject Evaluable) (string, bool) { - log.Debug("looking up %q @ %s...", key, subject) + log.Debugf("looking up %q @ %s...", key, subject) value := "" ok := false @@ -198,7 +198,7 @@ func KeyValue(key string, subject Evaluable) (string, bool) { value = strings.Join(vals, vsep) } - log.Debug("%q @ %s => %q, %v", key, subject, value, ok) + log.Debugf("%q @ %s => %q, %v", key, subject, value, ok) return value, ok } @@ -258,10 +258,10 @@ func ResolveRef(subject Evaluable, spec string) (string, bool, error) { obj interface{} = subject ) - log.Debug("resolving %q in %s...", key, subject) + log.Debugf("resolving %q in %s...", key, subject) for { - log.Debug("- resolve %q in %s", key, obj) + log.Debugf("- resolve %q in %s", key, obj) switch v := obj.(type) { case Evaluable: @@ -294,11 +294,11 @@ func ResolveRef(subject Evaluable, spec string) (string, bool, error) { if !ok { err := exprError("%s: failed to resolve %q: non-string type %T", subject, spec, obj) - log.Error("internal error: %s", err) + log.Errorf("internal error: %s", err) return "", false, err } - log.Debug("resolved %q in %s => %s", spec, subject, s) + log.Debugf("resolved %q in %s => %s", spec, subject, s) return s, true, nil } diff --git a/pkg/cpuallocator/allocator.go b/pkg/cpuallocator/allocator.go index ae4e93eea..3a98f0319 100644 --- a/pkg/cpuallocator/allocator.go +++ b/pkg/cpuallocator/allocator.go @@ -185,7 +185,7 @@ func newAllocatorHelper(sys sysfs.System, topo topologyCache) *allocatorHelper { // Allocate full idle CPU packages. func (a *allocatorHelper) takeIdlePackages() { - a.Debug("* takeIdlePackages()...") + a.Debugf("* takeIdlePackages()...") offline := a.sys.Offlined() @@ -212,7 +212,7 @@ func (a *allocatorHelper) takeIdlePackages() { return pkgs[i] < pkgs[j] }) - a.Debug(" => idle packages sorted by preference: %v", pkgs) + a.Debugf(" => idle packages sorted by preference: %v", pkgs) // take as many idle packages as we need/can for _, id := range pkgs { @@ -220,9 +220,9 @@ func (a *allocatorHelper) takeIdlePackages() { if a.prefer < NumCPUPriorities { cset = cset.Intersection(a.topology.cpuPriorities[a.prefer]) } - a.Debug(" => considering package %v (#%s)...", id, cset) + a.Debugf(" => considering package %v (#%s)...", id, cset) if a.cnt >= cset.Size() { - a.Debug(" => taking package %v...", id) + a.Debugf(" => taking package %v...", id) a.result = a.result.Union(cset) a.from = a.from.Difference(cset) a.cnt -= cset.Size() @@ -246,12 +246,12 @@ func (a *allocatorHelper) takeIdleClusters() { if len(a.topology.kind) > 1 { // we only take E-clusters for low-prio requests if a.prefer != PriorityLow && c.kind == sysfs.EfficientCore { - a.Debug(" - omit %s, CPU preference is %s", c, a.prefer) + a.Debugf(" - omit %s, CPU preference is %s", c, a.prefer) return false, emptyCPUSet } // we only take P-clusters for other than low-prio requests if a.prefer == PriorityLow && c.kind == sysfs.PerformanceCore { - a.Debug(" - omit %s, CPU preference is %s", c, a.prefer) + a.Debugf(" - omit %s, CPU preference is %s", c, a.prefer) return false, emptyCPUSet } } @@ -260,25 +260,25 @@ func (a *allocatorHelper) takeIdleClusters() { cset := c.cpus.Difference(offline) free := cset.Intersection(a.from) if free.IsEmpty() || !free.Equals(cset) { - a.Debug(" - omit %s, %d usable CPUs (%s)", c, free.Size(), free) + a.Debugf(" - omit %s, %d usable CPUs (%s)", c, free.Size(), free) return false, emptyCPUSet } - a.Debug(" + pick %s, %d usable CPUs (%s)", c, free.Size(), free) + a.Debugf(" + pick %s, %d usable CPUs (%s)", c, free.Size(), free) return true, free } preferTightestFit = func(cA, cB *cpuCluster, pkgA, pkgB, dieA, dieB int, csetA, csetB cpuset.CPUSet) (r int) { defer func() { if r < 0 { - a.Debug(" + prefer %s", cA) - a.Debug(" over %s", cB) + a.Debugf(" + prefer %s", cA) + a.Debugf(" over %s", cB) } if r > 0 { - a.Debug(" + prefer %s", cB) - a.Debug(" over %s", cA) + a.Debugf(" + prefer %s", cB) + a.Debugf(" over %s", cA) } - a.Debug(" - misfit %s", cA) - a.Debug(" and %s", cB) + a.Debugf(" - misfit %s", cA) + a.Debugf(" and %s", cB) }() // prefer cluster which alone can satisfy the request, preferring tighter @@ -355,13 +355,13 @@ func (a *allocatorHelper) takeIdleClusters() { } ) - a.Debug("* takeIdleClusters()...") + a.Debugf("* takeIdleClusters()...") if len(a.topology.clusters) <= 1 { return } - a.Debug("looking for %d %s CPUs from %s", a.cnt, a.prefer, a.from) + a.Debugf("looking for %d %s CPUs from %s", a.cnt, a.prefer, a.from) a.sortCPUClusters(sorter) @@ -379,7 +379,7 @@ func (a *allocatorHelper) takeIdleClusters() { c := clusters[0] cset := cpus[c] if cset.Size() == a.cnt { - log.Debug("=> picking single %s", c) + log.Debugf("=> picking single %s", c) a.result = a.result.Union(cset) a.from = a.from.Difference(cset) a.cnt -= cset.Size() @@ -388,13 +388,13 @@ func (a *allocatorHelper) takeIdleClusters() { // tightest-fit cluster is too big, so allocation can't consume any cluster fully if cset.Size() > a.cnt { - log.Debug(" => tightest-fit cluster too big, can't consume a full cluster") + log.Debugf(" => tightest-fit cluster too big, can't consume a full cluster") return } // bail out if no package can satisfy the allocation if cnt := pkgCPUCnt[c.pkg]; cnt < a.cnt { - log.Debug(" => no package can satisfy the allocation, bail out") + log.Debugf(" => no package can satisfy the allocation, bail out") } // start consuming clusters, until we're done @@ -402,13 +402,13 @@ func (a *allocatorHelper) takeIdleClusters() { cset := cpus[c] if a.cnt < cset.Size() { - log.Debug("=> %d more CPUs needed after allocation of %d clusters", a.cnt, i) + log.Debugf("=> %d more CPUs needed after allocation of %d clusters", a.cnt, i) // XXX TODO: should restrict a.from to the same package, if that has enough // CPUs to satisfy the request return } - log.Debug("=> picking %d. %s", i, c) + log.Debugf("=> picking %d. %s", i, c) if a.cnt >= cset.Size() { a.result = a.result.Union(cset) @@ -424,7 +424,7 @@ func (a *allocatorHelper) takeIdleClusters() { // Allocate idle or partial CPU last-level cache groups. func (a *allocatorHelper) takeCacheGroups() { - log.Debug("* takeCacheGroups()...") + log.Debugf("* takeCacheGroups()...") if len(a.topology.cacheGroups) <= 1 { return @@ -472,12 +472,12 @@ func (a *allocatorHelper) takeCacheGroups() { if len(a.topology.kind) > 1 { // only take E-groups for low-prio requests, or if we have none other if a.prefer != PriorityLow && g.kind == sysfs.EfficientCore { - log.Debug(" - ignore %s (CPU preference is %s)", g, a.prefer) + log.Debugf(" - ignore %s (CPU preference is %s)", g, a.prefer) return pickIgnore, emptyCPUSet } // only take P-groups for other than low-prio requests, or if we have none other if a.prefer == PriorityLow && g.kind == sysfs.PerformanceCore { - log.Debug(" - ignore %s (CPU preference is %s)", g, a.prefer) + log.Debugf(" - ignore %s (CPU preference is %s)", g, a.prefer) return pickIgnore, emptyCPUSet } } @@ -487,18 +487,18 @@ func (a *allocatorHelper) takeCacheGroups() { // ignore groups without usable CPUs if free.IsEmpty() { - log.Debug(" - ignore %s (no usable CPUs)", g) + log.Debugf(" - ignore %s (no usable CPUs)", g) return pickIgnore, emptyCPUSet } // prefer fully usable idle groups if free.Equals(cset) { - log.Debug(" + prefer %s (%d CPUs: %s)", g, free.Size(), free) + log.Debugf(" + prefer %s (%d CPUs: %s)", g, free.Size(), free) return pickPrefer, free } // take also groups with some usable CPUs left - log.Debug(" o usable %s (%d free CPUs: %s)", g, free.Size(), free) + log.Debugf(" o usable %s (%d free CPUs: %s)", g, free.Size(), free) return pickUsable, free } @@ -506,14 +506,14 @@ func (a *allocatorHelper) takeCacheGroups() { defer func() { switch { case r < 0: - log.Debug(" + prefer %s", gA) - log.Debug(" over %s", gB) + log.Debugf(" + prefer %s", gA) + log.Debugf(" over %s", gB) case r > 0: - log.Debug(" + prefer %s", gB) - log.Debug(" over %s", gA) + log.Debugf(" + prefer %s", gB) + log.Debugf(" over %s", gA) default: // currently should not happen - log.Debug(" - either %s", gA) - log.Debug(" or %s", gB) + log.Debugf(" - either %s", gA) + log.Debugf(" or %s", gB) } }() @@ -617,14 +617,14 @@ func (a *allocatorHelper) takeCacheGroups() { defer func() { switch { case r < 0: - log.Debug(" + prefer %s", gA) - log.Debug(" over %s", gB) + log.Debugf(" + prefer %s", gA) + log.Debugf(" over %s", gB) case r > 0: - log.Debug(" + prefer %s", gB) - log.Debug(" over %s", gA) + log.Debugf(" + prefer %s", gB) + log.Debugf(" over %s", gA) default: - log.Debug(" - either %s", gA) - log.Debug(" or %s", gB) + log.Debugf(" - either %s", gA) + log.Debugf(" or %s", gB) } }() @@ -709,7 +709,7 @@ func (a *allocatorHelper) takeCacheGroups() { } ) - log.Debug("looking for %d CPUs (prio %s) from %s", a.cnt, a.prefer, a.from) + log.Debugf("looking for %d CPUs (prio %s) from %s", a.cnt, a.prefer, a.from) sorter.sortCacheGroups(a) @@ -734,7 +734,7 @@ func (a *allocatorHelper) takeCacheGroups() { } if preferPkgCPUs+usablePkgCPUs < a.cnt { - log.Debug("=> no package can satisfy the allocation") + log.Debugf("=> no package can satisfy the allocation") return } @@ -742,7 +742,7 @@ func (a *allocatorHelper) takeCacheGroups() { // take full idle cache groups, splitting up the last one if necessary // - log.Debug("trying to take idle cache groups...") + log.Debugf("trying to take idle cache groups...") for i, g := range sorter.prefer { if cnt <= 0 { break @@ -751,7 +751,7 @@ func (a *allocatorHelper) takeCacheGroups() { cset := sorter.cpus[g] if cnt >= cset.Size() { - log.Debug("=> took full idle cache group %d. %s", i, g) + log.Debugf("=> took full idle cache group %d. %s", i, g) result = result.Union(cset) from = from.Difference(cset) @@ -767,7 +767,7 @@ func (a *allocatorHelper) takeCacheGroups() { ta.cnt = cnt use := ta.allocate() - log.Debug("=> took %d CPUs (%s) from idle cache group %d. %s", use.Size(), use, i, g) + log.Debugf("=> took %d CPUs (%s) from idle cache group %d. %s", use.Size(), use, i, g) result = result.Union(use) from = from.Difference(use) @@ -790,7 +790,7 @@ func (a *allocatorHelper) takeCacheGroups() { // 3. fulfill request by taking groups in decreasing size order // - log.Debug("%d more CPUs needed", cnt) + log.Debugf("%d more CPUs needed", cnt) var ( groupsBySize = map[int][]*cacheGroup{} @@ -813,23 +813,23 @@ func (a *allocatorHelper) takeCacheGroups() { } if totalCPUs < cnt { - log.Debug("=> internal error: total cache group CPUs %d <= expected %d", totalCPUs, cnt) + log.Debugf("=> internal error: total cache group CPUs %d <= expected %d", totalCPUs, cnt) } // try to pick a single exact sized group if possible - log.Debug("trying to find a single cache group with %d CPUs...", cnt) + log.Debugf("trying to find a single cache group with %d CPUs...", cnt) if groups, ok := groupsBySize[cnt]; ok { g := groups[0] cset := sorter.cpus[g] - log.Debug("=> took remaining %d CPUs (%s) of usable cache group %s", cnt, cset, g) + log.Debugf("=> took remaining %d CPUs (%s) of usable cache group %s", cnt, cset, g) result = result.Union(cset) from = from.Difference(cset) if cset.Size() != cnt { - log.Error("=> internal error: group size by cnt %d != expected %d", cset.Size(), cnt) + log.Errorf("=> internal error: group size by cnt %d != expected %d", cset.Size(), cnt) return } @@ -840,7 +840,7 @@ func (a *allocatorHelper) takeCacheGroups() { } // try picking the smallest number of groups of a single size - log.Debug("trying to find cache groups of a single size for %d more CPUs...", cnt) + log.Debugf("trying to find cache groups of a single size for %d more CPUs...", cnt) size := 0 take := 0 @@ -857,7 +857,7 @@ func (a *allocatorHelper) takeCacheGroups() { for i, g := range groupsBySize[size] { cset := sorter.cpus[g] - log.Debug("=> took %d./%d %d remaining CPUs (%s) of usable cache group of size %d %s", + log.Debugf("=> took %d./%d %d remaining CPUs (%s) of usable cache group of size %d %s", i+1, take, cset.Size(), cset, size, g) result = result.Union(cset) @@ -866,7 +866,7 @@ func (a *allocatorHelper) takeCacheGroups() { } if cnt != 0 { - log.Error("internal error: remaining cnt %d, expected 0", cnt) + log.Errorf("internal error: remaining cnt %d, expected 0", cnt) return } @@ -876,7 +876,7 @@ func (a *allocatorHelper) takeCacheGroups() { } // use up smallest number of groups possible (start with the largest group) - log.Debug("=> taking cache groups in decreasing size order for %d more CPUs...", cnt) + log.Debugf("=> taking cache groups in decreasing size order for %d more CPUs...", cnt) var ( grpCnt = 0 @@ -892,7 +892,7 @@ func (a *allocatorHelper) takeCacheGroups() { } if cpuCnt < cnt { - log.Debug("=> internal error: %d CPUs in usable cache groups < needed %d", cpuCnt, cnt) + log.Debugf("=> internal error: %d CPUs in usable cache groups < needed %d", cpuCnt, cnt) return } @@ -904,7 +904,7 @@ func (a *allocatorHelper) takeCacheGroups() { break } - log.Debug("=> took %d./%d remaining CPUs (%s) of usable cache group %s", i, grpCnt, cset, g) + log.Debugf("=> took %d./%d remaining CPUs (%s) of usable cache group %s", i, grpCnt, cset, g) result = result.Union(cset) from = from.Difference(cset) @@ -923,7 +923,7 @@ func (a *allocatorHelper) takeCacheGroups() { ta.cnt = cnt use := ta.allocate() - log.Debug("=> took %d./%d %d CPUs (%s) from cache group %s", + log.Debugf("=> took %d./%d %d CPUs (%s) from cache group %s", grpCnt, grpCnt, use.Size(), use, g) result = result.Union(use) @@ -932,7 +932,7 @@ func (a *allocatorHelper) takeCacheGroups() { } if cnt != 0 { - log.Error("=> internal error: %d unallocated cache group CPUs remain", cnt) + log.Errorf("=> internal error: %d unallocated cache group CPUs remain", cnt) return } @@ -943,7 +943,7 @@ func (a *allocatorHelper) takeCacheGroups() { // Allocate full idle CPU cores. func (a *allocatorHelper) takeIdleCores() { - a.Debug("* takeIdleCores()...") + a.Debugf("* takeIdleCores()...") offline := a.sys.Offlined() @@ -966,14 +966,14 @@ func (a *allocatorHelper) takeIdleCores() { return cores[i] < cores[j] }) - a.Debug(" => idle cores sorted by preference: %v", cores) + a.Debugf(" => idle cores sorted by preference: %v", cores) // take as many idle cores as we can for _, id := range cores { cset := a.topology.core[id].Difference(offline) - a.Debug(" => considering core %v (#%s)...", id, cset) + a.Debugf(" => considering core %v (#%s)...", id, cset) if a.cnt >= cset.Size() { - a.Debug(" => taking core %v...", id) + a.Debugf(" => taking core %v...", id) a.result = a.result.Union(cset) a.from = a.from.Difference(cset) a.cnt -= cset.Size() @@ -995,7 +995,7 @@ func (a *allocatorHelper) takeIdleThreads() { return a.from.Difference(offline).Contains(int(id)) }) - a.Debug(" => idle threads unsorted: %v", cores) + a.Debugf(" => idle threads unsorted: %v", cores) // sorted for preference by id, mimicking cpus_assignment.go for now: // IOW, prefer CPUs @@ -1054,12 +1054,12 @@ func (a *allocatorHelper) takeIdleThreads() { return iCore < jCore }) - a.Debug(" => idle threads sorted: %v", cores) + a.Debugf(" => idle threads sorted: %v", cores) // take as many idle cores as we can for _, id := range cores { cset := a.topology.core[id].Difference(offline) - a.Debug(" => considering thread %v (#%s)...", id, cset) + a.Debugf(" => considering thread %v (#%s)...", id, cset) cset = cpuset.New(int(id)) a.result = a.result.Union(cset) a.from = a.from.Difference(cset) @@ -1073,7 +1073,7 @@ func (a *allocatorHelper) takeIdleThreads() { // takeAny is a dummy allocator not dependent on sysfs topology information func (a *allocatorHelper) takeAny() { - a.Debug("* takeAnyCores()...") + a.Debugf("* takeAnyCores()...") cpus := a.from.List() @@ -1140,7 +1140,7 @@ func (a *allocatorHelper) sortCPUClusters(s *clusterSorter) { cpus = map[*cpuCluster]cpuset.CPUSet{} ) - a.Debug("picking suitable clusters") + a.Debugf("picking suitable clusters") for _, c := range a.topology.clusters { var cset cpuset.CPUSet @@ -1170,20 +1170,20 @@ func (a *allocatorHelper) sortCPUClusters(s *clusterSorter) { } if a.DebugEnabled() { - log.Debug("number of collected usable CPUs:") + log.Debugf("number of collected usable CPUs:") for pkg, cnt := range pkgCPUCnt { - log.Debug(" - package #%d: %d", pkg, cnt) + log.Debugf(" - package #%d: %d", pkg, cnt) } for pkg, dies := range dieCPUCnt { for die, cnt := range dies { - log.Debug(" - die #%d/%d %d", pkg, die, cnt) + log.Debugf(" - die #%d/%d %d", pkg, die, cnt) } } } // sort collected clusters if s.sort != nil { - a.Debug("sorting picked clusters") + a.Debugf("sorting picked clusters") slices.SortFunc(clusters, func(cA, cB *cpuCluster) int { pkgCPUsA, pkgCPUsB := pkgCPUCnt[cA.pkg], pkgCPUCnt[cB.pkg] dieCPUsA, dieCPUsB := dieCPUCnt[cA.pkg][cA.die], dieCPUCnt[cB.pkg][cB.die] @@ -1260,7 +1260,7 @@ func (s *cacheGroupSorter) sortCacheGroups(a *allocatorHelper) { s.usableDie = map[idset.ID]map[idset.ID]int{} s.cpus = map[*cacheGroup]cpuset.CPUSet{} - log.Debug("picking suitable cache groups") + log.Debugf("picking suitable cache groups") // Notes: // We blindly assume here that all cache groups of interest are of @@ -1305,37 +1305,37 @@ func (s *cacheGroupSorter) sortCacheGroups(a *allocatorHelper) { if log.DebugEnabled() { if len(s.preferPkg) > 0 { - log.Debug("number of preferred cache group CPUs per package/die:") + log.Debugf("number of preferred cache group CPUs per package/die:") for pkg, cnt := range s.preferPkg { - log.Debug(" - package #%d: %d", pkg, cnt) + log.Debugf(" - package #%d: %d", pkg, cnt) } for pkg, dies := range s.preferDie { for die, cnt := range dies { - log.Debug(" - die #%d/%d %d", pkg, die, cnt) + log.Debugf(" - die #%d/%d %d", pkg, die, cnt) } } } else { - log.Debug("no preferred cache groups found") + log.Debugf("no preferred cache groups found") } if len(s.usablePkg) > 0 { - log.Debug("number of non-preferred but usable cache group CPUs per package/die:") + log.Debugf("number of non-preferred but usable cache group CPUs per package/die:") for pkg, cnt := range s.usablePkg { - log.Debug(" - package #%d: %d", pkg, cnt) + log.Debugf(" - package #%d: %d", pkg, cnt) } for pkg, dies := range s.usableDie { for die, cnt := range dies { - log.Debug(" - die #%d/%d %d", pkg, die, cnt) + log.Debugf(" - die #%d/%d %d", pkg, die, cnt) } } } else { - log.Debug("no non-preferred but usable cache groups found") + log.Debugf("no non-preferred but usable cache groups found") } } // sort preferred groups if len(s.prefer) > 0 { - log.Debug("sorting preferred cache groups") + log.Debugf("sorting preferred cache groups") slices.SortFunc(s.prefer, func(gA, gB *cacheGroup) int { return s.sortPrefer(gA, gB, s) }) @@ -1343,7 +1343,7 @@ func (s *cacheGroupSorter) sortCacheGroups(a *allocatorHelper) { // sort other usable groups if len(s.usable) > 0 { - log.Debug("sorting non-preferred but usable cache groups") + log.Debugf("sorting non-preferred but usable cache groups") slices.SortFunc(s.usable, func(gA, gB *cacheGroup) int { return s.sortUsable(gA, gB, s) }) @@ -1371,7 +1371,7 @@ func (ca *cpuAllocator) allocateCpus(from *cpuset.CPUSet, cnt int, options ...Op result, err, *from = a.allocate(), nil, a.from.Clone() - a.Debug("%d cpus from #%v (preferring #%v) => #%v", cnt, from.Union(result), a.prefer, result) + a.Debugf("%d cpus from #%v (preferring #%v) => #%v", cnt, from.Union(result), a.prefer, result) } return result, err @@ -1389,7 +1389,7 @@ func (ca *cpuAllocator) ReleaseCpus(from *cpuset.CPUSet, cnt int, options ...Opt result, err := ca.allocateCpus(from, from.Size()-cnt, options...) - ca.Debug("ReleaseCpus(#%s, %d) => kept: #%s, released: #%s", oset, cnt, from, result) + ca.Debugf("ReleaseCpus(#%s, %d) => kept: #%s, released: #%s", oset, cnt, from, result) return result, err } @@ -1454,7 +1454,7 @@ func (c *topologyCache) discoverCPUPriorities(sys sysfs.System) { cset = cset.Difference(ecores) } - log.Debug("package #%d (%s): %d %s priority cpus (%v)", id, source, len(cpus), CPUPriority(p), cset) + log.Debugf("package #%d (%s): %d %s priority cpus (%v)", id, source, len(cpus), CPUPriority(p), cset) prio[p] = prio[p].Union(cset) } } @@ -1479,7 +1479,7 @@ func (c *topologyCache) discoverSstCPUPriority(sys sysfs.System, pkgID idset.ID) switch { case sst == nil: case sst.TFEnabled: - log.Debug("package #%d: using SST-TF based CPU prioritization", pkgID) + log.Debugf("package #%d: using SST-TF based CPU prioritization", pkgID) // We only look at the CLOS id as SST-TF (seems to) follows ordered CLOS priority for _, i := range cpuIDs { id := idset.ID(i) @@ -1493,7 +1493,7 @@ func (c *topologyCache) discoverSstCPUPriority(sys sysfs.System, pkgID idset.ID) active = true case sst.CPEnabled: closPrio := c.sstClosPriority(sys, pkgID) - log.Debug("package #%d: using SST-CP based CPU prioritization with CLOS mapping %v", pkgID, closPrio) + log.Debugf("package #%d: using SST-CP based CPU prioritization with CLOS mapping %v", pkgID, closPrio) active = false for _, i := range cpuIDs { @@ -1508,7 +1508,7 @@ func (c *topologyCache) discoverSstCPUPriority(sys sysfs.System, pkgID idset.ID) } if !active && sst != nil && sst.BFEnabled { - log.Debug("package #%d: using SST-BF based CPU prioritization", pkgID) + log.Debugf("package #%d: using SST-BF based CPU prioritization", pkgID) for _, i := range cpuIDs { id := idset.ID(i) p := PriorityLow @@ -1556,7 +1556,7 @@ func (c *topologyCache) sstClosPriority(sys sysfs.System, pkgID idset.ID) map[in if sstinfo.CPPriority == sst.Ordered { // In ordered mode the priority is simply the CLOS id closSorted = sortedKeys(closIds) - log.Debug("package #%d, ordered SST-CP priority with CLOS ids %v", pkgID, closSorted) + log.Debugf("package #%d, ordered SST-CP priority with CLOS ids %v", pkgID, closSorted) } else { // In proportional mode we sort by the proportional priority parameter closPpSorted := sortedKeys(closPps) @@ -1564,7 +1564,7 @@ func (c *topologyCache) sstClosPriority(sys sysfs.System, pkgID idset.ID) map[in for _, pp := range closPpSorted { closSorted = append(closSorted, closPps[pp]) } - log.Debug("package #%d, proportional SST-CP priority with PP-to-CLOS parity %v", pkgID, closPps) + log.Debugf("package #%d, proportional SST-CP priority with PP-to-CLOS parity %v", pkgID, closPps) } // Map from CLOS id to cpuallocator CPU priority @@ -1677,9 +1677,9 @@ func (c *topologyCache) discoverCPUClusters(sys sysfs.System) { } } if len(clusters) > 1 { - log.Debug("package #%d has %d clusters:", id, len(clusters)) + log.Debugf("package #%d has %d clusters:", id, len(clusters)) for _, cl := range clusters { - log.Debug(" die #%d, cluster #%d: %s cpus %s", + log.Debugf(" die #%d, cluster #%d: %s cpus %s", cl.die, cl.cluster, cl.kind, cl.cpus) } c.clusters = append(c.clusters, clusters...) @@ -1729,11 +1729,11 @@ func (c *topologyCache) discoverCacheGroups(sys sysfs.System) { n := c.pickCacheLevelForGrouping(sys) if n < 0 { - log.Info("no cache level provides useful CPU grouping") + log.Infof("no cache level provides useful CPU grouping") return } - log.Info("picked cache level %d for CPU grouping", n) + log.Infof("picked cache level %d for CPU grouping", n) online := sys.OnlineCPUs() for _, id := range sys.PackageIDs() { @@ -1800,19 +1800,19 @@ func (c *topologyCache) discoverCacheGroups(sys sysfs.System) { for _, cpuID := range g.cpus.UnsortedList() { cpu := sys.CPU(cpuID) if cpu.PackageID() != g.pkg { - log.Warn("CPU #%d in cache group #%d has package #%d != #%d", + log.Warnf("CPU #%d in cache group #%d has package #%d != #%d", cpuID, g.id, cpu.PackageID(), g.pkg) c.cacheGroups = nil return } if cpu.DieID() != g.die { - log.Warn("CPU #%d in cache group #%d has die #%d != #%d", + log.Warnf("CPU #%d in cache group #%d has die #%d != #%d", cpuID, g.id, cpu.DieID(), g.die) sortByDie = false break } if cpu.NodeID() != g.node { - log.Warn("CPU #%d in cache group #%d has node #%d != #%d", + log.Warnf("CPU #%d in cache group #%d has node #%d != #%d", cpuID, g.id, cpu.NodeID(), g.die) c.cacheGroups = nil return @@ -1820,7 +1820,7 @@ func (c *topologyCache) discoverCacheGroups(sys sysfs.System) { } cpu := sys.CPU(g.cpus.List()[0]) - log.Debug("cache group #%d: pkg #%d/die #%d/node #%d %s cpus %s", + log.Debugf("cache group #%d: pkg #%d/die #%d/node #%d %s cpus %s", g.id, cpu.PackageID(), cpu.DieID(), cpu.NodeID(), g.kind, g.cpus) } @@ -1834,7 +1834,7 @@ func (c *topologyCache) discoverCacheGroups(sys sysfs.System) { for idx, g := range c.cacheGroups { g.id = idx cpu := sys.CPU(g.cpus.List()[0]) - log.Debug("cache group #%d: pkg #%d/die #%d/node #%d %s cpus %s", + log.Debugf("cache group #%d: pkg #%d/die #%d/node #%d %s cpus %s", g.id, cpu.PackageID(), cpu.DieID(), cpu.NodeID(), g.kind, g.cpus) } } diff --git a/pkg/http/http.go b/pkg/http/http.go index 5b14e949e..6d087f6f2 100644 --- a/pkg/http/http.go +++ b/pkg/http/http.go @@ -52,10 +52,10 @@ func (mux *ServeMux) Handle(pattern string, handler http.Handler) { mux.Lock() defer mux.Unlock() - log.Debug("registering handler for %q...", pattern) + log.Debugf("registering handler for %q...", pattern) if _, ok := mux.handlers[pattern]; ok { - log.Error("can't register duplicate HTTP handler for %q", pattern) + log.Errorf("can't register duplicate HTTP handler for %q", pattern) return } @@ -68,10 +68,10 @@ func (mux *ServeMux) HandleFunc(pattern string, fn func(http.ResponseWriter, *ht mux.Lock() defer mux.Unlock() - log.Debug("registering handler function for %q...", pattern) + log.Debugf("registering handler function for %q...", pattern) if _, ok := mux.handlers[pattern]; ok { - log.Error("can't register duplicate HTTP handler function for '%s'", pattern) + log.Errorf("can't register duplicate HTTP handler function for '%s'", pattern) return } @@ -91,7 +91,7 @@ func (mux *ServeMux) Unregister(pattern string) (http.Handler, bool) { return nil, false } - log.Debug("unregistering handler for %q...", pattern) + log.Debugf("unregistering handler for %q...", pattern) delete(mux.handlers, pattern) mux.mux = http.NewServeMux() @@ -106,7 +106,7 @@ func (mux *ServeMux) Unregister(pattern string) (http.Handler, bool) { func (mux *ServeMux) ServeHTTP(w http.ResponseWriter, r *http.Request) { mux.RLock() defer mux.RUnlock() - log.Debug("serving %s...", r.URL) + log.Debugf("serving %s...", r.URL) mux.mux.ServeHTTP(w, r) } @@ -140,11 +140,11 @@ func (s *Server) GetAddress() string { // Start sets up the server to listen and serve on the given address. func (s *Server) Start(addr string) error { if addr == "" { - log.Info("%s is disabled", httpServer) + log.Infof("%s is disabled", httpServer) return nil } - log.Info("starting %s...", httpServer) + log.Infof("starting %s...", httpServer) s.Lock() defer s.Unlock() @@ -164,7 +164,7 @@ func (s *Server) Start(addr string) error { go func() { err := s.server.Serve(ln) if err != nil && err != http.ErrServerClosed { - log.Warn("HTTP server exited with error: %v", err) + log.Warnf("HTTP server exited with error: %v", err) } }() @@ -173,7 +173,7 @@ func (s *Server) Start(addr string) error { // Stop Close()'s the server immediately. func (s *Server) Stop() { - log.Info("stopping %s...", httpServer) + log.Infof("stopping %s...", httpServer) s.Lock() defer s.Unlock() @@ -190,7 +190,7 @@ func (s *Server) Stop() { func (s *Server) Shutdown(wait bool) { var sync chan struct{} - log.Info("shutting down %s...", httpServer) + log.Infof("shutting down %s...", httpServer) s.Lock() defer s.Unlock() @@ -215,7 +215,7 @@ func (s *Server) Shutdown(wait bool) { // Reconfigure reconfigures the server. func (s *Server) Reconfigure(addr string) error { - log.Info("reconfiguring %s...", httpServer) + log.Infof("reconfiguring %s...", httpServer) if s.GetAddress() != addr { return s.Restart(addr) @@ -225,7 +225,7 @@ func (s *Server) Reconfigure(addr string) error { // Restart restarts it on the given address. func (s *Server) Restart(addr string) error { - log.Info("restarting %s...", httpServer) + log.Infof("restarting %s...", httpServer) s.Stop() return s.Start(addr) diff --git a/pkg/instrumentation/instrumentation.go b/pkg/instrumentation/instrumentation.go index f85f8ade9..73d285719 100644 --- a/pkg/instrumentation/instrumentation.go +++ b/pkg/instrumentation/instrumentation.go @@ -62,7 +62,7 @@ func SetIdentity(attrs ...KeyValue) { // Start our instrumentation services. func Start() error { - log.Info("starting instrumentation services...") + log.Infof("starting instrumentation services...") lock.Lock() defer lock.Unlock() @@ -87,7 +87,7 @@ func Restart() error { err := start() if err != nil { - log.Error("failed to start instrumentation: %v", err) + log.Errorf("failed to start instrumentation: %v", err) } return err diff --git a/pkg/instrumentation/metrics/metrics.go b/pkg/instrumentation/metrics/metrics.go index 075d396ea..1f60d80dd 100644 --- a/pkg/instrumentation/metrics/metrics.go +++ b/pkg/instrumentation/metrics/metrics.go @@ -115,14 +115,14 @@ func Start(m *http.ServeMux, resource *resource.Resource, opts ...Option) error metrics.Configure(enabled) if exporter == "" { - log.Info("no metrics exporter configured, metrics collection disabled") + log.Infof("no metrics exporter configured, metrics collection disabled") metrics.SetProvider(nil) metrics.Configure(nil) return nil } if m == nil { - log.Info("no mux provided, metrics collection disabled") + log.Infof("no mux provided, metrics collection disabled") metrics.SetProvider(nil) metrics.Configure(nil) return nil @@ -135,7 +135,7 @@ func Start(m *http.ServeMux, resource *resource.Resource, opts ...Option) error switch exporter { case promExporter: - log.Info("using OpenTelemetry Prometheus exporter") + log.Infof("using OpenTelemetry Prometheus exporter") // To enable/disable 'standard' OpenTelemetry or runtime-provided // metrics we either use the default prometheus registerer (enabled) @@ -164,7 +164,7 @@ func Start(m *http.ServeMux, resource *resource.Resource, opts ...Option) error m.Handle("/metrics", promhttp.HandlerFor(gatherer, handlerOpts)) case httpExporter: - log.Info("using OpenTelemetry HTTP exporter") + log.Infof("using OpenTelemetry HTTP exporter") exp, err := otlpmetrichttp.New(ctx) if err != nil { @@ -178,7 +178,7 @@ func Start(m *http.ServeMux, resource *resource.Resource, opts ...Option) error ) case grpcExporter: - log.Info("using OpenTelemetry gRPC exporter") + log.Infof("using OpenTelemetry gRPC exporter") exp, err := otlpmetricgrpc.New(ctx) if err != nil { @@ -192,7 +192,7 @@ func Start(m *http.ServeMux, resource *resource.Resource, opts ...Option) error ) } - log.Info("starting metrics exporter...") + log.Infof("starting metrics exporter...") provider = metric.NewMeterProvider(options...) metrics.SetProvider(provider) @@ -212,7 +212,7 @@ func Stop() { if provider != nil { err := provider.Shutdown(context.Background()) if err != nil { - log.Error("failed to shut down metrics provider: %v", err) + log.Errorf("failed to shut down metrics provider: %v", err) } provider = nil } diff --git a/pkg/instrumentation/tracing/tracing.go b/pkg/instrumentation/tracing/tracing.go index 1ecffdd95..9056922f5 100644 --- a/pkg/instrumentation/tracing/tracing.go +++ b/pkg/instrumentation/tracing/tracing.go @@ -115,7 +115,7 @@ func Stop() { } func (t *tracing) start(resource *resource.Resource, options ...Option) error { - log.Info("starting tracing exporter...") + log.Infof("starting tracing exporter...") for _, opt := range options { if err := opt(t); err != nil { @@ -129,7 +129,7 @@ func (t *tracing) start(resource *resource.Resource, options ...Option) error { } if t.endpoint == "" { - log.Info("tracing effectively disabled, no endpoint set") + log.Infof("tracing effectively disabled, no endpoint set") t.sampler.setSampler(nil) return nil } diff --git a/pkg/resmgr/cache/affinity.go b/pkg/resmgr/cache/affinity.go index 5059db488..b1d93c9d9 100644 --- a/pkg/resmgr/cache/affinity.go +++ b/pkg/resmgr/cache/affinity.go @@ -91,14 +91,14 @@ func (cch *cache) EvaluateAffinity(a *Affinity) map[string]int32 { // FilterScope returns the containers selected by the scope expression. func (cch *cache) FilterScope(scope *resmgr.Expression) []Container { - log.Debug("calculating scope %s", scope.String()) + log.Debugf("calculating scope %s", scope.String()) result := []Container{} for _, c := range cch.GetContainers() { if scope.Evaluate(c) { - log.Debug(" + container %s: IN scope", c.PrettyName()) + log.Debugf(" + container %s: IN scope", c.PrettyName()) result = append(result, c) } else { - log.Debug(" - container %s: NOT IN scope", c.PrettyName()) + log.Debugf(" - container %s: NOT IN scope", c.PrettyName()) } } return result diff --git a/pkg/resmgr/cache/cache.go b/pkg/resmgr/cache/cache.go index 10b4f8d89..d66000894 100644 --- a/pkg/resmgr/cache/cache.go +++ b/pkg/resmgr/cache/cache.go @@ -607,7 +607,7 @@ func (cch *cache) SetActivePolicy(policy string) error { // ResetActivePolicy clears the active policy any any policy-specific data from the cache. func (cch *cache) ResetActivePolicy() error { - log.Warn("clearing all data for active policy (%q) from cache...", + log.Warnf("clearing all data for active policy (%q) from cache...", cch.PolicyName) cch.PolicyName = "" @@ -635,7 +635,7 @@ func (cch *cache) DeletePod(id string) Pod { return nil } - log.Debug("removing pod %s (%s)", p.PrettyName(), p.GetID()) + log.Debugf("removing pod %s (%s)", p.PrettyName(), p.GetID()) delete(cch.Pods, id) if err := cch.Save(); err != nil { @@ -655,7 +655,7 @@ func (cch *cache) LookupPod(id string) (Pod, bool) { func WithContainerState(state ContainerState) InsertContainerOption { return func(c *container) { if c.Ctr.State != state { - log.Info("overriding inserted container state to %v (reported %v)", state, c.Ctr.State) + log.Infof("overriding inserted container state to %v (reported %v)", state, c.Ctr.State) c.Ctr.State = state } } @@ -688,7 +688,7 @@ func (cch *cache) DeleteContainer(id string) Container { return nil } - log.Debug("removing container %s", c.PrettyName()) + log.Debugf("removing container %s", c.PrettyName()) if err := cch.removeContainerDirectory(c.GetID()); err != nil { log.Warnf("failed to remove container directory for %s: %v", c.GetID(), err) } @@ -709,7 +709,7 @@ func (cch *cache) LookupContainer(id string) (Container, bool) { // LookupContainerByCgroup looks up the container for the given cgroup path. func (cch *cache) LookupContainerByCgroup(path string) (Container, bool) { - log.Debug("resolving %s to a container...", path) + log.Debugf("resolving %s to a container...", path) for _, c := range cch.Containers { parent := "" @@ -743,20 +743,20 @@ func (cch *cache) RefreshPods(pods []*nri.PodSandbox, resCh <-chan *podresapi.Po for _, item := range pods { valid[item.Id] = struct{}{} if _, ok := cch.Pods[item.Id]; !ok { - log.Debug("inserting discovered pod %s...", item.Id) + log.Debugf("inserting discovered pod %s...", item.Id) pod := cch.InsertPod(item, nil) add = append(add, pod) } } for _, pod := range cch.Pods { if _, ok := valid[pod.GetID()]; !ok { - log.Debug("purging stale pod %s...", pod.GetID()) + log.Debugf("purging stale pod %s...", pod.GetID()) del = append(del, cch.DeletePod(pod.GetID())) } } for _, c := range cch.Containers { if _, ok := valid[c.GetPodID()]; !ok { - log.Debug("purging container %s of stale pod %s...", c.GetID(), c.GetPodID()) + log.Debugf("purging container %s of stale pod %s...", c.GetID(), c.GetPodID()) cch.DeleteContainer(c.GetID()) c.UpdateState(ContainerStateStale) containers = append(containers, c) @@ -785,10 +785,10 @@ func (cch *cache) RefreshContainers(containers []*nri.Container) ([]Container, [ for _, c := range containers { valid[c.Id] = struct{}{} if _, ok := cch.Containers[c.Id]; !ok { - log.Debug("inserting discovered container %s...", c.Id) + log.Debugf("inserting discovered container %s...", c.Id) inserted, err := cch.InsertContainer(c) if err != nil { - log.Error("failed to insert discovered container %s to cache: %v", + log.Errorf("failed to insert discovered container %s to cache: %v", c.Id, err) } else { add = append(add, inserted) @@ -798,7 +798,7 @@ func (cch *cache) RefreshContainers(containers []*nri.Container) ([]Container, [ for _, c := range cch.Containers { if _, ok := valid[c.GetID()]; !ok { - log.Debug("purging stale container %s (state: %v)...", c.GetID(), c.GetState()) + log.Debugf("purging stale container %s (state: %v)...", c.GetID(), c.GetState()) cch.DeleteContainer(c.GetID()) c.UpdateState(ContainerStateStale) del = append(del, c) @@ -875,9 +875,9 @@ func (cch *cache) SetPolicyEntry(key string, obj interface{}) { if log.DebugEnabled() { if data, err := marshalEntry(obj); err != nil { - log.Error("marshalling of policy entry '%s' failed: %v", key, err) + log.Errorf("marshalling of policy entry '%s' failed: %v", key, err) } else { - log.Debug("policy entry '%s' set to '%s'", key, string(data)) + log.Debugf("policy entry '%s' set to '%s'", key, string(data)) } } } @@ -1102,7 +1102,7 @@ func (cch *cache) checkPerm(what, path string, isDir bool, p *permissions) (bool // warn if permissions are less strict than the preferred defaults if (existing | expected) != expected { - log.Warn("existing %s %q has less strict permissions %v than expected %v", + log.Warnf("existing %s %q has less strict permissions %v than expected %v", what, path, existing, expected) } @@ -1217,7 +1217,7 @@ func (cch *cache) UnblockSave() error { case cch.saveBlock == 0: return cch.Save() case cch.saveBlock < 0: - log.Error("cache save block counter went negative, resetting to 0") + log.Errorf("cache save block counter went negative, resetting to 0") cch.saveBlock = 0 } return nil @@ -1229,7 +1229,7 @@ func (cch *cache) Save() error { return nil } - log.Debug("saving cache to file '%s'...", cch.filePath) + log.Debugf("saving cache to file '%s'...", cch.filePath) data, err := cch.Snapshot() if err != nil { @@ -1250,16 +1250,16 @@ func (cch *cache) Save() error { // Load loads the last saved state of the cache. func (cch *cache) Load() error { - log.Debug("loading cache from file '%s'...", cch.filePath) + log.Debugf("loading cache from file '%s'...", cch.filePath) data, err := os.ReadFile(cch.filePath) switch { case os.IsNotExist(err): - log.Debug("no cache file '%s', nothing to restore", cch.filePath) + log.Debugf("no cache file '%s', nothing to restore", cch.filePath) return nil case len(data) == 0: - log.Debug("empty cache file '%s', nothing to restore", cch.filePath) + log.Debugf("empty cache file '%s', nothing to restore", cch.filePath) return nil case err != nil: return cacheError("failed to load cache from file '%s': %v", cch.filePath, err) diff --git a/pkg/resmgr/cache/container.go b/pkg/resmgr/cache/container.go index 735de0717..b0982ca09 100644 --- a/pkg/resmgr/cache/container.go +++ b/pkg/resmgr/cache/container.go @@ -78,16 +78,16 @@ func (c *container) getAllowDenyPathList(typeStr string) *PathList { ) if value, ok = c.GetEffectiveAnnotation(key); !ok { - log.Info("no hint %s-list annotation (%s) for %s", typeStr, key, c.PrettyName()) + log.Infof("no hint %s-list annotation (%s) for %s", typeStr, key, c.PrettyName()) return nil } if err := yaml.Unmarshal([]byte(value), &list); err != nil { - log.Error("failed to parse hint %s-list (%s) for %s: %v", typeStr, key, c.PrettyName(), err) + log.Errorf("failed to parse hint %s-list (%s) for %s: %v", typeStr, key, c.PrettyName(), err) return nil } - log.Debug("got hint %s-list for %s: %v", typeStr, c.PrettyName(), list) + log.Debugf("got hint %s-list for %s: %v", typeStr, c.PrettyName(), list) return &list } @@ -118,9 +118,9 @@ func (cch *cache) createContainer(nriCtr *nri.Container, opts ...InsertContainer } if c.PodResources == nil { - log.Info("no pod resources for container %s", c.PrettyName()) + log.Infof("no pod resources for container %s", c.PrettyName()) } else { - log.Info("got pod resources %+v", c.PodResources) + log.Infof("got pod resources %+v", c.PodResources) } for _, opt := range opts { @@ -152,12 +152,12 @@ func checkAllowedAndDeniedPaths(hostPath string, allowPathList, denyPathList *Pa } if err != nil { - log.Error("Malformed pattern \"%s\"", matched) + log.Errorf("Malformed pattern \"%s\"", matched) return false } if matched { - log.Debug("Deny match, removing %s from hints", path) + log.Debugf("Deny match, removing %s from hints", path) denied = true break } @@ -177,12 +177,12 @@ func checkAllowedAndDeniedPaths(hostPath string, allowPathList, denyPathList *Pa } if err != nil { - log.Error("Malformed pattern \"%s\"", matched) + log.Errorf("Malformed pattern \"%s\"", matched) return denied } if matched { - log.Debug("Allow match, adding %s to hints", path) + log.Debugf("Allow match, adding %s to hints", path) return false } } @@ -202,7 +202,7 @@ func (c *container) generateTopologyHints() { if preference, ok := c.GetEffectiveAnnotation(TopologyHintsKey); ok { if genHints, err := strconv.ParseBool(preference); err == nil { if !genHints { - log.Info("%s: automatic topology hint generation disabled", c.PrettyName()) + log.Infof("%s: automatic topology hint generation disabled", c.PrettyName()) return } } else { @@ -228,10 +228,10 @@ func (c *container) generateTopologyHints() { deviceHints = true podResourceHints = true case NoHints: - log.Info("%s: automatic topology hint generation disabled", c.PrettyName()) + log.Infof("%s: automatic topology hint generation disabled", c.PrettyName()) return default: - log.Error("%s: invalid preference %s (annotation '%s=%s'): ignoring it", + log.Errorf("%s: invalid preference %s (annotation '%s=%s'): ignoring it", c.PrettyName(), pref, TopologyHintsKey, preference) } } @@ -249,7 +249,7 @@ func (c *container) generateTopologyHints() { } } } else { - log.Info("automatic topology hint generation disabled for mounts") + log.Infof("automatic topology hint generation disabled for mounts") } if deviceHints { @@ -261,7 +261,7 @@ func (c *container) generateTopologyHints() { } } } else { - log.Info("automatic topology hint generation disabled for devices") + log.Infof("automatic topology hint generation disabled for devices") } if podResourceHints { @@ -274,20 +274,20 @@ func (c *container) generateTopologyHints() { c.TopologyHints = topology.MergeTopologyHints(c.TopologyHints, hints) } } else { - log.Info("automatic topology hint generation disabled for pod resources") + log.Infof("automatic topology hint generation disabled for pod resources") } if testHints { hints := map[string]topology.Hint{} if value, ok := c.GetEffectiveAnnotation(TestTopologyHintsKey); ok { if err := yaml.Unmarshal([]byte(value), &hints); err != nil { - log.Error("failed to parse test topology hints annotation for %s: %v", + log.Errorf("failed to parse test topology hints annotation for %s: %v", c.PrettyName(), err) } else { for p, h := range hints { h.Provider = p hints[h.Provider] = h - log.Info("%s: injected test topology hint %v", c.PrettyName(), h) + log.Infof("%s: injected test topology hint %v", c.PrettyName(), h) } c.TopologyHints = topology.MergeTopologyHints(c.TopologyHints, hints) } @@ -338,7 +338,7 @@ func (c *container) GetAnnotatedResources() (v1.ResourceRequirements, bool) { annotated := &kubernetes.AnnotatedResources{} if err := annotated.Unmarshal([]byte(data)); err != nil { - log.Error("failed to unmarshal annotated resources for pod %s: %v", + log.Errorf("failed to unmarshal annotated resources for pod %s: %v", pod.PrettyName(), err) return v1.ResourceRequirements{}, false } @@ -350,7 +350,7 @@ func (c *container) GetAnnotatedResources() (v1.ResourceRequirements, bool) { // Estimate resource requirements using the containers cgroup parameters and QoS class. func (c *container) estimateResourceRequirements() { if annotated, ok := c.GetAnnotatedResources(); ok { - log.Info("%s: using annotated resources %+v", c.PrettyName(), annotated) + log.Infof("%s: using annotated resources %+v", c.PrettyName(), annotated) c.Requirements = annotated return } @@ -450,7 +450,7 @@ func (c *container) GetAnnotation(key string, objPtr interface{}) (string, bool) if objPtr != nil { if err := json.Unmarshal([]byte(jsonStr), objPtr); err != nil { - log.Error("failed to unmarshal annotation %s (%s) of pod %s into %T", + log.Errorf("failed to unmarshal annotation %s (%s) of pod %s into %T", key, jsonStr, c.GetID(), objPtr) return "", false } @@ -576,7 +576,7 @@ func (c *container) SetResourceUpdates(r *nri.LinuxResources) bool { } func mergeNRIResources(u *nri.LinuxResources, orig *nri.LinuxResources) *nri.LinuxResources { - log.Debug("merging resource update %+v with fallback/orig %+v", u, orig) + log.Debugf("merging resource update %+v with fallback/orig %+v", u, orig) if u.Cpu == nil { u.Cpu = &nri.LinuxCPU{} @@ -611,7 +611,7 @@ func mergeNRIResources(u *nri.LinuxResources, orig *nri.LinuxResources) *nri.Lin } } - log.Debug("merged resource update: %+v", u) + log.Debugf("merged resource update: %+v", u) return u } @@ -648,7 +648,7 @@ func (c *container) StrictTopologyHints() bool { strict, err := strconv.ParseBool(value) if err != nil { - log.Error("%s: invalid strict topology hints annotation (%q, %q): %v", + log.Errorf("%s: invalid strict topology hints annotation (%q, %q): %v", c.PrettyName(), StrictTopologyHintsKey, value, err) return false } @@ -676,7 +676,7 @@ func (c *container) GetPendingAdjustment() *nri.ContainerAdjustment { req, ok := c.request.(*nri.ContainerAdjustment) if !ok { - log.Error("%s: queried pending adjustment has mismatching type %T", + log.Errorf("%s: queried pending adjustment has mismatching type %T", c.PrettyName(), c.request) req = nil } @@ -692,7 +692,7 @@ func (c *container) GetPendingUpdate() *nri.ContainerUpdate { req, ok := c.request.(*nri.ContainerUpdate) if !ok { - log.Error("%s: queried pending update has mismatching type %T", + log.Errorf("%s: queried pending update has mismatching type %T", c.PrettyName(), c.request) req = nil } @@ -706,7 +706,7 @@ func (c *container) InsertMount(m *Mount) { adjust, ok := c.getPendingRequest().(*nri.ContainerAdjustment) if !ok { - log.Error("%s: can't insert mount %s -> %s, container is not being created", + log.Errorf("%s: can't insert mount %s -> %s, container is not being created", c.PrettyName(), m.Source, m.Destination) return } @@ -757,7 +757,7 @@ func (c *container) SetCPUShares(value int64) { case *nri.ContainerUpdate: req.SetLinuxCPUShares(uint64(value)) default: - log.Error("%s: can't set CPU shares (%d): incorrect pending request type %T", + log.Errorf("%s: can't set CPU shares (%d): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -774,7 +774,7 @@ func (c *container) SetCPUQuota(value int64) { case *nri.ContainerUpdate: req.SetLinuxCPUQuota(value) default: - log.Error("%s: can't set CPU quota (%d): incorrect pending request type %T", + log.Errorf("%s: can't set CPU quota (%d): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -791,7 +791,7 @@ func (c *container) SetCPUPeriod(value int64) { case *nri.ContainerUpdate: req.SetLinuxCPUPeriod(value) default: - log.Error("%s: can't set CPU period (%d): incorrect pending request type %T", + log.Errorf("%s: can't set CPU period (%d): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -808,7 +808,7 @@ func (c *container) SetCpusetCpus(value string) { case *nri.ContainerUpdate: req.SetLinuxCPUSetCPUs(value) default: - log.Error("%s: can't set cpuset CPUs (%s): incorrect pending request type %T", + log.Errorf("%s: can't set cpuset CPUs (%s): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -825,7 +825,7 @@ func (c *container) SetCpusetMems(value string) { case *nri.ContainerUpdate: req.SetLinuxCPUSetMems(value) default: - log.Error("%s: can't set cpuset memory (%s): incorrect pending request type %T", + log.Errorf("%s: can't set cpuset memory (%s): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -842,7 +842,7 @@ func (c *container) SetMemoryLimit(value int64) { case *nri.ContainerUpdate: req.SetLinuxMemoryLimit(value) default: - log.Error("%s: can't set memory limit (%d): incorrect pending request type %T", + log.Errorf("%s: can't set memory limit (%d): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -859,7 +859,7 @@ func (c *container) SetMemorySwap(value int64) { case *nri.ContainerUpdate: req.SetLinuxMemorySwap(value) default: - log.Error("%s: can't set memory swap (%d): incorrect pending request type %T", + log.Errorf("%s: can't set memory swap (%d): incorrect pending request type %T", c.PrettyName(), value, c.request) return } @@ -879,7 +879,7 @@ func (c *container) setSchedulingOnAdjustment(setter func(sch *nri.LinuxSchedule setter(sch) req.SetLinuxScheduler(sch) default: - log.Error("%s: can't set scheduling parameter: incorrect pending request type %T", + log.Errorf("%s: can't set scheduling parameter: incorrect pending request type %T", c.PrettyName(), c.request) return } @@ -937,7 +937,7 @@ func (c *container) setIOPriorityOnAdjustment(setter func(iop *nri.LinuxIOPriori setter(iop) req.SetLinuxIOPriority(iop) default: - log.Error("%s: can't set IO priority parameter: incorrect pending request type %T", + log.Errorf("%s: can't set IO priority parameter: incorrect pending request type %T", c.PrettyName(), c.request) return } @@ -1023,7 +1023,7 @@ func getTopologyHintsForMount(hostPath, containerPath string, readOnly bool, all return topology.Hints{} } - log.Debug("getting topology hints for mount %s (at %s)", hostPath, containerPath) + log.Debugf("getting topology hints for mount %s (at %s)", hostPath, containerPath) // ignore topology information for small files in /etc, service files in /var/lib/kubelet and host libraries mounts ignoredTopologyPaths := []string{"/.nri-resource-policy", "/etc/", "/dev/termination-log", "/lib/", "/lib64/", "/usr/lib/", "/usr/lib32/", "/usr/lib64/"} @@ -1063,7 +1063,7 @@ func getTopologyHintsForMount(hostPath, containerPath string, readOnly bool, all } func getTopologyHintsForDevice(devType string, major, minor int64, allowPathList, denyPathList *PathList) topology.Hints { - log.Debug("getting topology hints for device <%s %d,%d>", devType, major, minor) + log.Debugf("getting topology hints for device <%s %d,%d>", devType, major, minor) if devPath, err := topology.FindGivenSysFsDevice(devType, major, minor); err == nil { if denied := checkAllowedAndDeniedPaths(devPath, allowPathList, denyPathList); denied { @@ -1083,16 +1083,16 @@ func getTopologyHintsForDevice(devType string, major, minor int64, allowPathList func (c *container) GetAffinity() ([]*Affinity, error) { pod, ok := c.GetPod() if !ok { - log.Error("internal error: can't find Pod for container %s", c.PrettyName()) + log.Errorf("internal error: can't find Pod for container %s", c.PrettyName()) } affinity, err := pod.GetContainerAffinity(c.GetName()) if err != nil { return nil, err } affinity = append(affinity, c.implicitAffinities(len(affinity) > 0)...) - log.Debug("affinity for container %s:", c.PrettyName()) + log.Debugf("affinity for container %s:", c.PrettyName()) for _, a := range affinity { - log.Debug(" - %s", a.String()) + log.Debugf(" - %s", a.String()) } return affinity, nil @@ -1127,7 +1127,7 @@ func (c *container) SetRDTClass(class string) { c.PrettyName(), class) } default: - log.Error("%s: can't set RDT class (%s): incorrect pending request type %T", + log.Errorf("%s: can't set RDT class (%s): incorrect pending request type %T", c.PrettyName(), class, c.request) return } @@ -1159,7 +1159,7 @@ func (c *container) SetBlockIOClass(class string) { c.PrettyName(), class) } default: - log.Error("%s: can't set block I/O class (%s): incorrect pending request type %T", + log.Errorf("%s: can't set block I/O class (%s): incorrect pending request type %T", c.PrettyName(), class, req) return } @@ -1249,12 +1249,12 @@ func (c *container) implicitAffinities(hasExplicit bool) []*Affinity { for name, generate := range c.cache.implicit { implicit := generate(c, hasExplicit) if implicit == nil { - log.Debug("no implicit affinity %s for container %s", + log.Debugf("no implicit affinity %s for container %s", name, c.PrettyName()) continue } - log.Debug("using implicit affinity %s for %s", name, c.PrettyName()) + log.Debugf("using implicit affinity %s for %s", name, c.PrettyName()) affinities = append(affinities, implicit) } return affinities diff --git a/pkg/resmgr/cache/pod.go b/pkg/resmgr/cache/pod.go index 6927e364f..799114f06 100644 --- a/pkg/resmgr/cache/pod.go +++ b/pkg/resmgr/cache/pod.go @@ -38,7 +38,7 @@ func (cch *cache) createPod(nriPod *nri.PodSandbox, ch <-chan *podresapi.PodReso p.goFetchPodResources(ch) if err := p.parseCgroupForQOSClass(); err != nil { - log.Error("pod %s: %v", p.PrettyName(), err) + log.Errorf("pod %s: %v", p.PrettyName(), err) } return p @@ -149,19 +149,19 @@ func (p *pod) goFetchPodResources(ch <-chan *podresapi.PodResources) { if p.podResCh != nil { p.PodResources = <-p.podResCh - log.Debug("fetched pod resources %+v for %s", p.PodResources, p.GetName()) + log.Debugf("fetched pod resources %+v for %s", p.PodResources, p.GetName()) } }() } func (p *pod) setPodResources(podRes *podresapi.PodResources) { p.PodResources = podRes - log.Debug("set pod resources %+v for %s", p.PodResources, p.GetName()) + log.Debugf("set pod resources %+v for %s", p.PodResources, p.GetName()) } func (p *pod) GetPodResources() *podresapi.PodResources { if p.waitResCh != nil { - log.Debug("waiting for pod resources fetch to complete...") + log.Debugf("waiting for pod resources fetch to complete...") <-p.waitResCh } return p.PodResources @@ -179,7 +179,7 @@ func (p *pod) GetContainerAffinity(name string) ([]*Affinity, error) { weight := DefaultWeight if !affinity.parseSimple(p, value, weight) { if err := affinity.parseFull(p, value, weight); err != nil { - log.Error("%v", err) + log.Errorf("%v", err) return nil, err } } @@ -189,18 +189,18 @@ func (p *pod) GetContainerAffinity(name string) ([]*Affinity, error) { weight := -DefaultWeight if !affinity.parseSimple(p, value, weight) { if err := affinity.parseFull(p, value, weight); err != nil { - log.Error("%v", err) + log.Errorf("%v", err) return nil, err } } } if log.DebugEnabled() { - log.Debug("Pod container affinity for %s:", p.GetName()) + log.Debugf("Pod container affinity for %s:", p.GetName()) for id, ca := range *affinity { - log.Debug(" - container %s:", id) + log.Debugf(" - container %s:", id) for _, a := range ca { - log.Debug(" * %s", a.String()) + log.Debugf(" * %s", a.String()) } } } @@ -294,7 +294,7 @@ func (p *pod) getTasks(recursive, processes bool) ([]string, error) { continue } - log.Error("%s: failed to read pids of %s: %v", p.PrettyName(), c.GetName(), err) + log.Errorf("%s: failed to read pids of %s: %v", p.PrettyName(), c.GetName(), err) } } diff --git a/pkg/resmgr/cache/utils.go b/pkg/resmgr/cache/utils.go index 92432c71c..3e7a90ba7 100644 --- a/pkg/resmgr/cache/utils.go +++ b/pkg/resmgr/cache/utils.go @@ -65,7 +65,7 @@ func estimateResourceRequirements(r *nri.LinuxResources, qosClass corev1.PodQOSC resources.Requests[corev1.ResourceMemory] = resources.Limits[corev1.ResourceMemory] case corev1.PodQOSBurstable: if req := OomAdjToMemReq(oomAdj, memLimit); req != nil && *req != 0 { - log.Info("estimated memory request: %d (%.2fM)", *req, float64(*req)/(1024*1024)) + log.Infof("estimated memory request: %d (%.2fM)", *req, float64(*req)/(1024*1024)) qty := resapi.NewQuantity(*req, resapi.DecimalSI) resources.Requests[corev1.ResourceMemory] = *qty } diff --git a/pkg/resmgr/control/control.go b/pkg/resmgr/control/control.go index 9418e877d..96d958c4c 100644 --- a/pkg/resmgr/control/control.go +++ b/pkg/resmgr/control/control.go @@ -113,7 +113,7 @@ func (c *control) StartStopControllers(cfg *cfgapi.Config) error { c.cfg = cfg.DeepCopy() - log.Info("syncing controllers with configuration...") + log.Infof("syncing controllers with configuration...") for _, controller := range c.controllers { if controller.running { @@ -212,7 +212,7 @@ func (c *control) runhook(controller *controller, hook string, container cache.C fn = controller.c.PostStopHook } - log.Debug("running %s %s hook for container %s", controller.name, hook, container.PrettyName()) + log.Debugf("running %s %s hook for container %s", controller.name, hook, container.PrettyName()) if err := fn(container); err != nil { return controlError("%s %s hook failed: %v", controller.name, hook, err) @@ -223,7 +223,7 @@ func (c *control) runhook(controller *controller, hook string, container cache.C // Register registers a new controller. func Register(name, description string, c Controller) error { - log.Info("registering controller %s...", name) + log.Infof("registering controller %s...", name) if oc, ok := controllers[name]; ok { return controlError("controller %s (%s) already registered.", oc.name, oc.description) diff --git a/pkg/resmgr/control/cpu/api.go b/pkg/resmgr/control/cpu/api.go index 01447353e..33bd02025 100644 --- a/pkg/resmgr/control/cpu/api.go +++ b/pkg/resmgr/control/cpu/api.go @@ -59,13 +59,13 @@ func Assign(c cache.Cache, class string, cpus ...int) error { // started. Enforcement of all assignments happens on StarT(), anyway. ctl := getCPUController() if err := ctl.enforceCpufreq(class, cpus...); err != nil { - log.Error("cpufreq enforcement failed: %v", err) + log.Errorf("cpufreq enforcement failed: %v", err) } if err := ctl.enforceCstates(class, cpus...); err != nil { - log.Error("cstate enforcement failed: %v", err) + log.Errorf("cstate enforcement failed: %v", err) } if err := ctl.enforceUncore(assignments, cpus...); err != nil { - log.Error("uncore frequency enforcement failed: %v", err) + log.Errorf("uncore frequency enforcement failed: %v", err) } } diff --git a/pkg/resmgr/control/cpu/cache.go b/pkg/resmgr/control/cpu/cache.go index 4b3bb28bb..0279dbd2d 100644 --- a/pkg/resmgr/control/cpu/cache.go +++ b/pkg/resmgr/control/cpu/cache.go @@ -32,7 +32,7 @@ func getClassAssignments(c cache.Cache) *cpuClassAssignments { a := &cpuClassAssignments{} if !c.GetPolicyEntry(cacheKeyCPUAssignments, a) { - log.Error("no cached state of CPU class assignments found") + log.Errorf("no cached state of CPU class assignments found") } return a diff --git a/pkg/resmgr/control/cpu/cpu.go b/pkg/resmgr/control/cpu/cpu.go index e07dcc5e9..90159a5fa 100644 --- a/pkg/resmgr/control/cpu/cpu.go +++ b/pkg/resmgr/control/cpu/cpu.go @@ -70,7 +70,7 @@ func isEmptyConfig(cfg *cfgapi.Config) bool { // Start initializes the controller for enforcing decisions. func (ctl *cpuctl) Start(cache cache.Cache, cfg *cfgapi.Config) (bool, error) { if isEmptyConfig(cfg) { - log.Info("empty configuration, disabling controller") + log.Infof("empty configuration, disabling controller") return false, nil } @@ -83,11 +83,11 @@ func (ctl *cpuctl) Start(cache cache.Cache, cfg *cfgapi.Config) (bool, error) { ctl.cache = cache // DEBUG: dump the class assignments we have stored in the cache - log.Debug("retrieved cpu class assignments from cache:\n%s", utils.DumpJSON(getClassAssignments(ctl.cache))) + log.Debugf("retrieved cpu class assignments from cache:\n%s", utils.DumpJSON(getClassAssignments(ctl.cache))) if err := ctl.configure(cfg); err != nil { // Just print an error. A config update later on may be valid. - log.Error("failed apply /cpuinitial configuration: %v", err) + log.Errorf("failed apply /cpuinitial configuration: %v", err) } ctl.started = true @@ -132,21 +132,21 @@ func (ctl *cpuctl) enforceCpufreq(class string, cpus ...int) error { } if min := int(c.MinFreq); min > 0 { - log.Debug("enforcing cpu frequency min %d from class %q on %v", min, class, cpus) + log.Debugf("enforcing cpu frequency min %d from class %q on %v", min, class, cpus) if err := utils.SetCPUsScalingMinFreq(cpus, min); err != nil { return fmt.Errorf("cannot set min freq %d: %w", min, err) } } if max := int(c.MaxFreq); max > 0 { - log.Debug("enforcing cpu frequency max %d from class %q on %v", max, class, cpus) + log.Debugf("enforcing cpu frequency max %d from class %q on %v", max, class, cpus) if err := utils.SetCPUsScalingMaxFreq(cpus, max); err != nil { return fmt.Errorf("cannot set max freq %d: %w", max, err) } } if governor := c.FreqGovernor; governor != "" { - log.Debug("enforcing cpu frequency governor %q from class %q on %v", governor, class, cpus) + log.Debugf("enforcing cpu frequency governor %q from class %q on %v", governor, class, cpus) if err := utils.SetScalingGovernorForCPUs(cpus, governor); err != nil { return fmt.Errorf("cannot set cpufreq governor %q: %w", governor, err) } @@ -182,7 +182,7 @@ func (ctl *cpuctl) enforceCstates(class string, cpus ...int) error { disCpuCstates := cpuCstates.Copy(cstates.NewBasicFilter().SetCstateNames(c.DisabledCstates...)) enCpuCstates.SetAttrs(cstates.AttrDisable, "0") disCpuCstates.SetAttrs(cstates.AttrDisable, "1") - log.Debug("enforcing cstates: enable: %v disable: %v from class %q on cpus %v", enabledCstates, c.DisabledCstates, class, cpus) + log.Debugf("enforcing cstates: enable: %v disable: %v from class %q on cpus %v", enabledCstates, c.DisabledCstates, class, cpus) if err := enCpuCstates.Apply(); err != nil { return fmt.Errorf("cannot enable cstates %v on cpus %v: %w", enabledCstates, cpus, err) } @@ -210,14 +210,14 @@ func (ctl *cpuctl) enforceUncore(assignments cpuClassAssignments, affectedCPUs . min, max, minCls, maxCls := effectiveUncoreFreqs(utils.NewIDSet(dieCPUs.List()...), ctl.classes, assignments) if min == 0 && max == 0 { - log.Debug("no uncore frequency limits for cpu package/die %d/%d", cpuPkgID, cpuDieID) + log.Debugf("no uncore frequency limits for cpu package/die %d/%d", cpuPkgID, cpuDieID) continue } - log.Debug("enforcing uncore min freq to %d (class %q), max freq to %d (class %q) on cpu package/die %d/%d", min, minCls, max, maxCls, cpuPkgID, cpuDieID) + log.Debugf("enforcing uncore min freq to %d (class %q), max freq to %d (class %q) on cpu package/die %d/%d", min, minCls, max, maxCls, cpuPkgID, cpuDieID) if min > 0 { if max > 0 && min > max { - log.Warn("uncore frequency limit min > max (%d > %d) on cpu package/die %d/%d", min, max, cpuPkgID, cpuDieID) + log.Warnf("uncore frequency limit min > max (%d > %d) on cpu package/die %d/%d", min, max, cpuPkgID, cpuDieID) } if err := utils.SetUncoreMinFreq(cpuPkgID, cpuDieID, int(min)); err != nil { @@ -287,7 +287,7 @@ func (ctl *cpuctl) configure(cfg *cfgapi.Config) error { assignments := *getClassAssignments(ctl.cache) // DEBUG: dump the class assignments we have stored in the cache - log.Debug("applying cpu controller configuration:\n%s", utils.DumpJSON(ctl.classes)) + log.Debugf("applying cpu controller configuration:\n%s", utils.DumpJSON(ctl.classes)) // Sanity check cstatesNeeded := map[string]bool{} @@ -326,24 +326,24 @@ func (ctl *cpuctl) configure(cfg *cfgapi.Config) error { if _, ok := ctl.classes[class]; ok { // Re-configure cpus (sysfs) according to new class parameters if err := ctl.enforceCpufreq(class, cpus.SortedMembers()...); err != nil { - log.Error("cpufreq enforcement on re-configure failed: %v", err) + log.Errorf("cpufreq enforcement on re-configure failed: %v", err) } if err := ctl.enforceCstates(class, cpus.SortedMembers()...); err != nil { - log.Error("cpufreq enforcement on re-configure failed: %v", err) + log.Errorf("cpufreq enforcement on re-configure failed: %v", err) } } else { // TODO: what should we really do with classes that do not exist in // the configuration anymore? Now we remember the CPUs assigned to // them. A further config update might re-introduce the class in // which case the CPUs will be reconfigured. - log.Warn("class %q with cpus %v missing from the configuration", class, cpus) + log.Warnf("class %q with cpus %v missing from the configuration", class, cpus) } } if err := ctl.enforceUncore(assignments); err != nil { - log.Error("uncore frequency enforcement on re-configure failed: %v", err) + log.Errorf("uncore frequency enforcement on re-configure failed: %v", err) } - log.Debug("cpu controller configured") + log.Debugf("cpu controller configured") return nil } diff --git a/pkg/resmgr/control/e2e-test/e2e-test.go b/pkg/resmgr/control/e2e-test/e2e-test.go index 5dfeab1e4..93cd882d9 100644 --- a/pkg/resmgr/control/e2e-test/e2e-test.go +++ b/pkg/resmgr/control/e2e-test/e2e-test.go @@ -69,7 +69,7 @@ func getE2ETestController() *testctl { // Start initializes the controller for enforcing decisions. func (ctl *testctl) Start(cache cache.Cache, cfg *cfgapi.Config) (bool, error) { - log.Debug("Start called (with test APIs %s)", + log.Debugf("Start called (with test APIs %s)", map[bool]string{false: "disabled", true: "enabled"}) if !enableTestAPIs { @@ -84,53 +84,53 @@ func (ctl *testctl) Start(cache cache.Cache, cfg *cfgapi.Config) (bool, error) { // Stop shuts down the controller. func (ctl *testctl) Stop() { - log.Debug("Stop called") + log.Debugf("Stop called") ctl.Log[controllerEvent] = append(ctl.Log[controllerEvent], "Stop") } // PreCreateHook handler for the e2e test controller. func (ctl *testctl) PreCreateHook(c cache.Container) error { - log.Debug("PreCreateHook called for %s", c.GetName()) + log.Debugf("PreCreateHook called for %s", c.GetName()) ctl.Log[preCreate] = append(ctl.Log[preCreate], c.GetName()) return nil } // PreStartHook handler for the e2e test controller. func (ctl *testctl) PreStartHook(c cache.Container) error { - log.Debug("PreStartHook called for %s", c.GetName()) + log.Debugf("PreStartHook called for %s", c.GetName()) ctl.Log[preStart] = append(ctl.Log[preStart], c.GetName()) return nil } // PostStartHook handler for the e2e test controller. func (ctl *testctl) PostStartHook(c cache.Container) error { - log.Debug("PostStartHook called for %s", c.GetName()) + log.Debugf("PostStartHook called for %s", c.GetName()) ctl.Log[postStart] = append(ctl.Log[postStart], c.GetName()) return nil } // PostUpdateHook handler for the e2e test controller. func (ctl *testctl) PostUpdateHook(c cache.Container) error { - log.Debug("PostUpdateHook called for %s", c.GetName()) + log.Debugf("PostUpdateHook called for %s", c.GetName()) ctl.Log[postUpdate] = append(ctl.Log[postUpdate], c.GetName()) return nil } // PostStopHook handler for the e2e test controller. func (ctl *testctl) PostStopHook(c cache.Container) error { - log.Debug("PostStopHook called for %s", c.GetName()) + log.Debugf("PostStopHook called for %s", c.GetName()) ctl.Log[postStop] = append(ctl.Log[postStop], c.GetName()) return nil } // dumpE2ETestControllerState prints internal info used by e2e testing script. func (ctl *testctl) dumpE2ETestControllerState(w http.ResponseWriter, req *http.Request) { - log.Debug("output E2E test controller state...") + log.Debugf("output E2E test controller state...") ctl.Lock() defer ctl.Unlock() - log.Debug("snapshot %v", ctl) + log.Debugf("snapshot %v", ctl) data, err := json.Marshal(ctl) if err != nil { diff --git a/pkg/resmgr/events.go b/pkg/resmgr/events.go index 1a9e3b7e7..37737ae6b 100644 --- a/pkg/resmgr/events.go +++ b/pkg/resmgr/events.go @@ -62,14 +62,14 @@ func (m *resmgr) SendEvent(event interface{}) error { // processEvent processes the given event. func (m *resmgr) processEvent(e interface{}) { - evtlog.Debug("received event of type %T...", e) + evtlog.Debugf("received event of type %T...", e) switch event := e.(type) { case string: - evtlog.Debug("'%s'...", event) + evtlog.Debugf("'%s'...", event) //case *events.Policy: //m.DeliverPolicyEvent(event) default: - evtlog.Warn("event of unexpected type %T...", e) + evtlog.Warnf("event of unexpected type %T...", e) } } diff --git a/pkg/resmgr/lib/memory/allocator.go b/pkg/resmgr/lib/memory/allocator.go index 18ed11e77..4939c4469 100644 --- a/pkg/resmgr/lib/memory/allocator.go +++ b/pkg/resmgr/lib/memory/allocator.go @@ -176,7 +176,7 @@ func (a *Allocator) ForeachRequest(req *Request, fn func(*Request) bool) { // request. Committing any offer invalidates all other offers. Allocating // or releasing memory likewise invalidates all offers. func (a *Allocator) GetOffer(req *Request) (*Offer, error) { - log.Debug("get offer for %s", req) + log.Debugf("get offer for %s", req) defer a.validateState("GetOffer") err := a.allocate(req) @@ -198,7 +198,7 @@ func (a *Allocator) GetOffer(req *Request) (*Offer, error) { // other existing allocations to fulfill the request. The caller must // ensure these updates are properly enforced. func (a *Allocator) Allocate(req *Request) (NodeMask, map[string]NodeMask, error) { - log.Debug("allocate %s memory for %s", req.types, req) + log.Debugf("allocate %s memory for %s", req.types, req) defer a.validateState("Allocate") defer a.cleanupUnusedZones() @@ -223,7 +223,7 @@ func (a *Allocator) Allocate(req *Request) (NodeMask, map[string]NodeMask, error // other existing allocations to fulfill the request. The caller must // ensure these updates are properly enforced. func (a *Allocator) Realloc(id string, affinity NodeMask, types TypeMask) (NodeMask, map[string]NodeMask, error) { - log.Debug("reallocate to add %s memory affine to %s for %s", types, affinity, id) + log.Debugf("reallocate to add %s memory affine to %s for %s", types, affinity, id) req, ok := a.requests[id] if !ok { @@ -242,7 +242,7 @@ func (a *Allocator) Release(id string) error { return fmt.Errorf("%w: no request with ID %s", ErrUnknownRequest, id) } - log.Debug("release memory for %s", req) + log.Debugf("release memory for %s", req) defer a.validateState("Release") defer a.cleanupUnusedZones() @@ -253,7 +253,7 @@ func (a *Allocator) Release(id string) error { // Reset resets the state of the allocator, releasing all allocations // and invalidating all offers. func (a *Allocator) Reset() { - log.Debug("reset allocations") + log.Debugf("reset allocations") a.reset() } @@ -307,7 +307,7 @@ func (a *Allocator) allocate(req *Request) (retErr error) { if retErr != nil { _, err := a.revertJournal(req) if err != nil { - log.Warn("failed to revert journal on error: %v", err) + log.Warnf("failed to revert journal on error: %v", err) } } }() @@ -332,7 +332,7 @@ func (a *Allocator) realloc(req *Request, nodes NodeMask, types TypeMask) (zone return req.Zone(), nil, nil } - log.Debug("reallocate to add %s memory affine to %s for %s", types, nodes, req) + log.Debugf("reallocate to add %s memory affine to %s for %s", types, nodes, req) if err = a.startJournal(); err != nil { return 0, nil, err @@ -342,7 +342,7 @@ func (a *Allocator) realloc(req *Request, nodes NodeMask, types TypeMask) (zone if retErr != nil { _, err := a.revertJournal(nil) if err != nil { - log.Warn("failed to revert journal on error: %v", err) + log.Warnf("failed to revert journal on error: %v", err) } } }() @@ -458,11 +458,11 @@ func (a *Allocator) validateState(where string) { for _, req := range a.requests { if assigned, ok := a.users[req.ID()]; ok { if assigned != req.Zone() { - log.Error("internal error: %s: %s assigned to %s, but has zone set to %s", + log.Errorf("internal error: %s: %s assigned to %s, but has zone set to %s", where, req, assigned, req.Zone()) } } else { - log.Error("internal error: %s: %s not assigned, but has zone set to %s", + log.Errorf("internal error: %s: %s not assigned, but has zone set to %s", where, req, req.Zone()) } } @@ -471,12 +471,12 @@ func (a *Allocator) validateState(where string) { for id, zReq := range z.users { req, ok := a.requests[id] if !ok { - log.Error("internal error: %s: %s present in zone %s, but has no assignment", + log.Errorf("internal error: %s: %s present in zone %s, but has no assignment", where, zReq, zone) continue } if req.Zone() != zone { - log.Error("internal error %s: %s assigned to %s, also present in zone %s", + log.Errorf("internal error %s: %s assigned to %s, also present in zone %s", where, req, req.Zone(), zone) } } @@ -502,7 +502,7 @@ func (a *Allocator) findInitialZone(req *Request) error { ) if miss != 0 { - log.Debug("- find initial zone (start at %s, expand with %s)", zone, miss) + log.Debugf("- find initial zone (start at %s, expand with %s)", zone, miss) nodes, _ := a.expand(zone, miss) zone |= nodes @@ -564,7 +564,7 @@ func (a *Allocator) ensureNormalMemory(req *Request) error { } } - log.Debug("- ensure normal memory for %s (with %s types)", zone, types) + log.Debugf("- ensure normal memory for %s (with %s types)", zone, types) for n, _ := a.expand(zone, types); n != 0; n, _ = a.expand(zone, types) { zone |= n @@ -600,7 +600,7 @@ func (a *Allocator) expand(zone NodeMask, types TypeMask) (NodeMask, TypeMask) { } if nodes != 0 { - log.Debug(" + %s expanded by %s %s to %s", zoneName(zone), types, nodes, zone|nodes) + log.Debugf(" + %s expanded by %s %s to %s", zoneName(zone), types, nodes, zone|nodes) } return nodes, types @@ -633,7 +633,7 @@ func (a *Allocator) defaultExpand(zone NodeMask, types TypeMask) (NodeMask, Type }) if newNodes != 0 { - details.Debug("expanded nodes %s by types %s to %s %s", zone, types, newTypes, newNodes) + details.Debugf("expanded nodes %s by types %s to %s %s", zone, types, newTypes, newNodes) } return newNodes, newTypes @@ -764,7 +764,7 @@ func (a *Allocator) checkOvercommit(nodes NodeMask) ([]NodeMask, map[NodeMask]in func (a *Allocator) cleanupUnusedZones() { for z, zone := range a.zones { if len(zone.users) == 0 { - log.Debug("removing unused zone %s...", z) + log.Debugf("removing unused zone %s...", z) delete(a.zones, z) } } @@ -800,7 +800,7 @@ func (a *Allocator) revertJournal(req *Request) (map[string]NodeMask, error) { return nil, nil } - log.Debug("reverting journal...") + log.Debugf("reverting journal...") j := a.journal a.journal = nil @@ -882,7 +882,7 @@ func (o *Offer) Commit() (NodeMask, map[string]NodeMask, error) { o.a.invalidateOffers() - log.Debug("committed offer %s to %s", o.req, o.req.Zone()) + log.Debugf("committed offer %s to %s", o.req, o.req.Zone()) return o.NodeMask(), o.Updates(), nil } diff --git a/pkg/resmgr/lib/memory/logging.go b/pkg/resmgr/lib/memory/logging.go index 8595207a9..3e797dbde 100644 --- a/pkg/resmgr/lib/memory/logging.go +++ b/pkg/resmgr/lib/memory/logging.go @@ -35,23 +35,23 @@ func (a *Allocator) DumpNodes(context ...interface{}) { ) if capa != 0 { - log.Info("%s %s node #%d with %d memory (%s)", prefix, + log.Infof("%s %s node #%d with %d memory (%s)", prefix, n.Type(), n.ID(), capa, prettySize(capa)) } else { - log.Info("%s memoryless %s node #%d", prefix, + log.Infof("%s memoryless %s node #%d", prefix, n.Type(), n.ID()) } - log.Info("%s distance vector %v", prefix, n.Distance().Vector()) + log.Infof("%s distance vector %v", prefix, n.Distance().Vector()) n.ForeachDistance(func(d int, nodes NodeMask) bool { - log.Info("%s at distance %d: %s %s", prefix, d, a.zoneType(nodes), nodes) + log.Infof("%s at distance %d: %s %s", prefix, d, a.zoneType(nodes), nodes) return true }) if cpus != "" { - log.Info("%s close CPUs: %s", prefix, cpus) + log.Infof("%s close CPUs: %s", prefix, cpus) } else { - log.Info("%s no close CPUs", prefix) + log.Infof("%s no close CPUs", prefix) } return true @@ -60,7 +60,7 @@ func (a *Allocator) DumpNodes(context ...interface{}) { func (a *Allocator) DumpConfig(context ...interface{}) { prefix := formatPrefix(context...) - log.Info("%smemory allocator configuration", prefix) + log.Infof("%smemory allocator configuration", prefix) a.DumpNodes(prefix) } @@ -78,13 +78,13 @@ func (a *Allocator) DumpRequests(context ...interface{}) { prefix := formatPrefix(context...) if len(a.users) == 0 { - details.Debug("%s no requests", prefix) + details.Debugf("%s no requests", prefix) return } - details.Debug("%s requests:", prefix) + details.Debugf("%s requests:", prefix) for _, req := range SortRequests(a.requests, nil, RequestsByAge) { - details.Debug("%s - %s (assigned zone %s)", prefix, req, req.Zone()) + details.Debugf("%s - %s (assigned zone %s)", prefix, req, req.Zone()) } } @@ -96,7 +96,7 @@ func (a *Allocator) DumpZones(prefixFmt ...interface{}) { prefix := formatPrefix(prefixFmt...) if len(a.zones) == 0 { - details.Debug("%s no zones in use", prefix) + details.Debugf("%s no zones in use", prefix) return } @@ -111,7 +111,7 @@ func (a *Allocator) DumpZones(prefixFmt ...interface{}) { return int(z1 - z2) }) - details.Debug("%s zones:", prefix) + details.Debugf("%s zones:", prefix) for _, z := range zones { var ( zone = a.zones[z] @@ -119,13 +119,13 @@ func (a *Allocator) DumpZones(prefixFmt ...interface{}) { capa = prettySize(a.ZoneCapacity(z)) used = prettySize(a.ZoneUsage(z)) ) - details.Debug("%s - zone %s, free %s (capacity %s, used %s)", prefix, z, free, capa, used) + details.Debugf("%s - zone %s, free %s (capacity %s, used %s)", prefix, z, free, capa, used) if len(zone.users) == 0 { continue } for _, req := range SortRequests(zone.users, nil, RequestsByAge) { - details.Debug("%s %s", prefix, req) + details.Debugf("%s %s", prefix, req) } } } @@ -135,11 +135,11 @@ func (a *Allocator) dumpOvercommit(where string, oc []NodeMask, spill map[NodeMa return } - log.Debug("%s", where) + log.Debugf("%s", where) for _, z := range oc { - log.Debug(" %s: %s", zoneName(z), prettySize(spill[z])) + log.Debugf(" %s: %s", zoneName(z), prettySize(spill[z])) for _, r := range a.zones[z].users { - log.Debug(" - user %s", r) + log.Debugf(" - user %s", r) } } } diff --git a/pkg/resmgr/lib/memory/mask-cache.go b/pkg/resmgr/lib/memory/mask-cache.go index 7c4f21566..a00a7c621 100644 --- a/pkg/resmgr/lib/memory/mask-cache.go +++ b/pkg/resmgr/lib/memory/mask-cache.go @@ -144,14 +144,14 @@ func (c *MaskCache) Clone() *MaskCache { // Log debug-dumps the contents of the cache. func (c *MaskCache) Dump(prefix, header string) { - log.Info("%s%s", header, prefix) - log.Info("%s - available types: %s", prefix, c.types) - log.Info("%s - available nodes: %s", prefix, c.nodes.all) - log.Info("%s has memory: %s", prefix, c.nodes.hasMemory) + log.Infof("%s%s", header, prefix) + log.Infof("%s - available types: %s", prefix, c.types) + log.Infof("%s - available nodes: %s", prefix, c.nodes.all) + log.Infof("%s has memory: %s", prefix, c.nodes.hasMemory) for types, nodes := range c.nodes.byTypes { - log.Info("%s %s: %s", prefix, types, nodes) + log.Infof("%s %s: %s", prefix, types, nodes) } - log.Info("%s no memory: %s", prefix, c.nodes.noMemory) - log.Info("%s has close CPUs: %s", prefix, c.nodes.hasCPU) - log.Info("%s no close CPUs: %s", prefix, c.nodes.noCPU) + log.Infof("%s no memory: %s", prefix, c.nodes.noMemory) + log.Infof("%s has close CPUs: %s", prefix, c.nodes.hasCPU) + log.Infof("%s no close CPUs: %s", prefix, c.nodes.noCPU) } diff --git a/pkg/resmgr/lib/memory/request.go b/pkg/resmgr/lib/memory/request.go index 7bf545660..fef08cd7c 100644 --- a/pkg/resmgr/lib/memory/request.go +++ b/pkg/resmgr/lib/memory/request.go @@ -150,7 +150,7 @@ func WithQosClass(qosClass string) RequestOption { case "guaranteed": return WithPriority(Guaranteed) default: - log.Error("%v: %q", ErrInvalidQosClass, qosClass) + log.Errorf("%v: %q", ErrInvalidQosClass, qosClass) return WithPriority(NoPriority) } } diff --git a/pkg/resmgr/lib/memory/zones.go b/pkg/resmgr/lib/memory/zones.go index 6306b9fa1..d2b5fa3d7 100644 --- a/pkg/resmgr/lib/memory/zones.go +++ b/pkg/resmgr/lib/memory/zones.go @@ -198,7 +198,7 @@ func (a *Allocator) zoneAssign(zone NodeMask, req *Request) { req.zone = zone a.journal.assign(zone, req.ID()) - log.Debug(" + %s: assign %s", zoneName(zone), req) + log.Debugf(" + %s: assign %s", zoneName(zone), req) } func (a *Allocator) zoneRemove(zone NodeMask, id string) { @@ -217,13 +217,13 @@ func (a *Allocator) zoneRemove(zone NodeMask, id string) { a.journal.delete(zone, id) req.zone = 0 - log.Debug(" - %s: remove %s", zoneName(zone), req) + log.Debugf(" - %s: remove %s", zoneName(zone), req) } func (a *Allocator) zoneMove(zone NodeMask, req *Request) { if from, ok := a.users[req.ID()]; ok { if from == zone { - log.Warn(" - %s: useless move of %s (same zone)...", zoneName(zone), req) + log.Warnf(" - %s: useless move of %s (same zone)...", zoneName(zone), req) return } a.zoneRemove(from, req.ID()) @@ -256,7 +256,7 @@ func (a *Allocator) zoneShrinkUsage(zone NodeMask, amount int64, limit Priority, nodes, types := a.expand(zone, z.types|extra) if nodes == 0 { - log.Debug(" - %s: couldn't expand by %s types", zoneName(zone), extra) + log.Debugf(" - %s: couldn't expand by %s types", zoneName(zone), extra) return 0 } @@ -276,7 +276,7 @@ func (a *Allocator) zoneShrinkUsage(zone NodeMask, amount int64, limit Priority, } } - log.Debug(" - %s: freed up %s bytes of memory", zoneName(zone), prettySize(moved)) + log.Debugf(" - %s: freed up %s bytes of memory", zoneName(zone), prettySize(moved)) return moved } diff --git a/pkg/resmgr/nri.go b/pkg/resmgr/nri.go index 134e86615..0678fe0bf 100644 --- a/pkg/resmgr/nri.go +++ b/pkg/resmgr/nri.go @@ -54,7 +54,7 @@ func newNRIPlugin(resmgr *resmgr) (*nriPlugin, error) { byname: make(map[string]cache.Container), } - nri.Info("creating plugin...") + nri.Infof("creating plugin...") return p, nil } @@ -82,7 +82,7 @@ func (p *nriPlugin) createStub() error { err error ) - nri.Info("creating plugin stub...") + nri.Infof("creating plugin stub...") if p.stub, err = stub.New(p, opts...); err != nil { return fmt.Errorf("failed to create NRI plugin stub: %w", err) @@ -96,7 +96,7 @@ func (p *nriPlugin) start() error { return nil } - nri.Info("starting plugin...") + nri.Infof("starting plugin...") if err := p.createStub(); err != nil { return err @@ -114,12 +114,12 @@ func (p *nriPlugin) stop() { return } - nri.Info("stopping plugin...") + nri.Infof("stopping plugin...") p.stub.Stop() } func (p *nriPlugin) onClose() { - nri.Error("connection to NRI/runtime lost, exiting...") + nri.Errorf("connection to NRI/runtime lost, exiting...") os.Exit(1) } @@ -142,11 +142,11 @@ func (p *nriPlugin) mapNameToContainer(ctr cache.Container) cache.Container { p.byname[name] = ctr if ok { - nri.Info("%s: remapped container from %s to %s", name, old.GetID(), ctr.GetID()) + nri.Infof("%s: remapped container from %s to %s", name, old.GetID(), ctr.GetID()) return old } - nri.Info("%s: mapped container to %s", name, ctr.GetID()) + nri.Infof("%s: mapped container to %s", name, ctr.GetID()) return nil } @@ -154,7 +154,7 @@ func (p *nriPlugin) unmapName(name string) (cache.Container, bool) { old, ok := p.byname[name] if ok { delete(p.byname, name) - nri.Info("%s: unmapped container from %s", name, old.GetID()) + nri.Infof("%s: unmapped container from %s", name, old.GetID()) } return old, ok } @@ -165,9 +165,9 @@ func (p *nriPlugin) unmapContainer(ctr cache.Container) { if ok { if old == ctr { delete(p.byname, name) - nri.Info("%s: unmapped container (%s)", name, ctr.GetID()) + nri.Infof("%s: unmapped container (%s)", name, ctr.GetID()) } else { - nri.Warn("%s: leaving container mapped, ID mismatch (%s != %s)", name, + nri.Warnf("%s: leaving container mapped, ID mismatch (%s != %s)", name, old.GetID(), ctr.GetID()) } } @@ -202,24 +202,24 @@ func (p *nriPlugin) syncWithNRI(pods []*api.PodSandbox, containers []*api.Contai allocated := []cache.Container{} released := []cache.Container{} - nri.Info("synchronizing cache state with NRI runtime...") + nri.Infof("synchronizing cache state with NRI runtime...") m.cache.BlockSave() defer func() { if err := m.cache.UnblockSave(); err != nil { - nri.Error("failed to unblock cache save: %v", err) + nri.Errorf("failed to unblock cache save: %v", err) } }() _, _, deleted := m.cache.RefreshPods(pods, m.agent.GoListPodResources(podResListTimeout)) for _, c := range deleted { - nri.Info("discovered stale container %s (%s)...", c.PrettyName(), c.GetID()) + nri.Infof("discovered stale container %s (%s)...", c.PrettyName(), c.GetID()) released = append(released, c) } _, deleted = m.cache.RefreshContainers(containers) for _, c := range deleted { - nri.Info("discovered stale container %s (%s)...", c.PrettyName(), c.GetID()) + nri.Infof("discovered stale container %s (%s)...", c.PrettyName(), c.GetID()) released = append(released, c) } @@ -230,7 +230,7 @@ func (p *nriPlugin) syncWithNRI(pods []*api.PodSandbox, containers []*api.Contai for _, c := range ctrs { switch c.GetState() { case cache.ContainerStateRunning, cache.ContainerStateCreated: - nri.Info("discovered created/running container %s (%s)...", + nri.Infof("discovered created/running container %s (%s)...", c.PrettyName(), c.GetID()) allocated = append(allocated, c) @@ -241,12 +241,12 @@ func (p *nriPlugin) syncWithNRI(pods []*api.PodSandbox, containers []*api.Contai case cache.ContainerStateExited: /* Treat stopped containers as deleted */ - nri.Info("discovered stopped container %s (%s)...", + nri.Infof("discovered stopped container %s (%s)...", c.PrettyName(), c.GetID()) released = append(released, c) default: - nri.Info("discovered container %s (%s), in state %v, ignoring it...", + nri.Infof("discovered container %s (%s), in state %v, ignoring it...", c.PrettyName(), c.GetID(), c.GetState()) } } @@ -274,7 +274,7 @@ func (p *nriPlugin) Synchronize(ctx context.Context, pods []*api.PodSandbox, con allocated, released, err := p.syncWithNRI(pods, containers) if err != nil { - nri.Error("failed to synchronize with NRI: %v", err) + nri.Errorf("failed to synchronize with NRI: %v", err) return nil, err } @@ -337,7 +337,7 @@ func (p *nriPlugin) StopPodSandbox(ctx context.Context, podSandbox *api.PodSandb m.agent.PurgePodResources(pod.GetNamespace(), pod.GetName()) if err := p.runPostReleaseHooks(event, released...); err != nil { - nri.Error("%s: failed to run post-release hooks for pod %s: %v", + nri.Errorf("%s: failed to run post-release hooks for pod %s: %v", event, pod.GetName(), err) } @@ -373,7 +373,7 @@ func (p *nriPlugin) RemovePodSandbox(ctx context.Context, podSandbox *api.PodSan m.agent.PurgePodResources(pod.GetNamespace(), pod.GetName()) if err := p.runPostReleaseHooks(event, released...); err != nil { - nri.Error("%s: failed to run post-release hooks for pod %s: %v", + nri.Errorf("%s: failed to run post-release hooks for pod %s: %v", event, pod.GetName(), err) } @@ -411,9 +411,9 @@ func (p *nriPlugin) CreateContainer(ctx context.Context, pod *api.PodSandbox, co } if old, ok := p.unmapName(c.PrettyName()); ok { - nri.Info("%s: releasing stale instance %s", c.PrettyName(), old.GetID()) + nri.Infof("%s: releasing stale instance %s", c.PrettyName(), old.GetID()) if err := m.policy.ReleaseResources(old); err != nil { - nri.Error("%s: failed to release stale instance %s", c.PrettyName(), old.GetID()) + nri.Errorf("%s: failed to release stale instance %s", c.PrettyName(), old.GetID()) } old.UpdateState(cache.ContainerStateExited) } @@ -433,7 +433,7 @@ func (p *nriPlugin) CreateContainer(ctx context.Context, pod *api.PodSandbox, co c.UpdateState(cache.ContainerStateCreated) if err := p.runPostAllocateHooks(event, c); err != nil { - nri.Error("%s: failed to run post-allocate hooks for %s: %v", + nri.Errorf("%s: failed to run post-allocate hooks for %s: %v", event, container.GetName(), err) relErr := p.runPostReleaseHooks(event, c) if relErr != nil { @@ -489,11 +489,11 @@ func (p *nriPlugin) StartContainer(ctx context.Context, pod *api.PodSandbox, con } if _, err := m.policy.HandleEvent(e); err != nil { - nri.Error("%s: policy failed to handle event %s: %v", event, e.Type, err) + nri.Errorf("%s: policy failed to handle event %s: %v", event, e.Type, err) } if err := p.runPostStartHooks(event, c); err != nil { - nri.Error("%s: failed to run post-start hooks for %s: %v", + nri.Errorf("%s: failed to run post-start hooks for %s: %v", event, c.PrettyName(), err) } @@ -527,7 +527,7 @@ func (p *nriPlugin) UpdateContainer(ctx context.Context, pod *api.PodSandbox, co } if realUpdates := c.SetResourceUpdates(res); !realUpdates { - nri.Warn("UpdateContainer with identical resources, short-circuiting it...") + nri.Warnf("UpdateContainer with identical resources, short-circuiting it...") if v := c.GetCPUShares(); v != 0 { c.SetCPUShares(v) } @@ -552,7 +552,7 @@ func (p *nriPlugin) UpdateContainer(ctx context.Context, pod *api.PodSandbox, co } else { old := c.GetResourceRequirements() upd, _ := c.GetResourceUpdates() - nri.Warn("UpdateContainer with real resource changes: %s -> %s", + nri.Warnf("UpdateContainer with real resource changes: %s -> %s", old.String(), upd.String()) if err := m.policy.UpdateResources(c); err != nil { return nil, fmt.Errorf("failed to update resources: %w", err) @@ -744,70 +744,70 @@ func (p *nriPlugin) dump(dir, event string, args ...interface{}) { case RunPodSandbox, StopPodSandbox, RemovePodSandbox: if dir == in { if len(args) != 1 { - nri.Error("%s %s ", dir, event, len(args)) + nri.Errorf("%s %s ", dir, event, len(args)) return } pod, ok := args[0].(*api.PodSandbox) if !ok { - nri.Error("%s %s ", dir, event, args[0]) + nri.Errorf("%s %s ", dir, event, args[0]) return } - nri.Info("%s %s %s/%s", dir, event, pod.GetNamespace(), pod.GetName()) + nri.Infof("%s %s %s/%s", dir, event, pod.GetNamespace(), pod.GetName()) p.dumpDetails(dir, event, pod) } else { if len(args) != 1 { - nri.Error("%s %s ", dir, event, len(args)) + nri.Errorf("%s %s ", dir, event, len(args)) return } err := args[0] if err != nil { - nri.Error("%s %s FAILED: %v", dir, event, err.(error)) + nri.Errorf("%s %s FAILED: %v", dir, event, err.(error)) return } - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) } case CreateContainer, StartContainer, StopContainer, RemoveContainer: if dir == in { if len(args) != 2 { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, len(args)) return } pod, ok := args[0].(*api.PodSandbox) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1]) return } ctr, ok := args[1].(*api.Container) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1]) return } - nri.Info("%s %s %s/%s/%s (%s)", dir, event, + nri.Infof("%s %s %s/%s/%s (%s)", dir, event, pod.GetNamespace(), pod.GetName(), ctr.GetName(), ctr.GetId()) p.dumpDetails(dir, event, ctr) } else { if len(args) < 1 { - nri.Error("%s %s ", dir, event) + nri.Errorf("%s %s ", dir, event) return } err := args[len(args)-1] if err != nil { - nri.Error("%s %s FAILED: %v", dir, event, err.(error)) + nri.Errorf("%s %s FAILED: %v", dir, event, err.(error)) return } - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) switch event { case CreateContainer: @@ -821,47 +821,47 @@ func (p *nriPlugin) dump(dir, event string, args ...interface{}) { case UpdateContainer: if dir == in { if len(args) != 3 { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, len(args)) return } pod, ok := args[0].(*api.PodSandbox) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1], args[2]) return } ctr, ok := args[1].(*api.Container) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1], args[2]) return } res, ok := args[2].(*api.LinuxResources) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1], args[2]) return } - nri.Info("%s %s %s/%s/%s (%s)", dir, event, + nri.Infof("%s %s %s/%s/%s (%s)", dir, event, pod.GetNamespace(), pod.GetName(), ctr.GetName(), ctr.GetId()) p.dumpDetails(dir, event, ctr) p.dumpDetails(dir, event, res) } else { if len(args) < 1 { - nri.Error("%s %s ", dir, event) + nri.Errorf("%s %s ", dir, event) return } err := args[len(args)-1] if err != nil { - nri.Error("%s %s FAILED: %v", dir, event, err.(error)) + nri.Errorf("%s %s FAILED: %v", dir, event, err.(error)) return } - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) switch event { case CreateContainer: @@ -875,82 +875,82 @@ func (p *nriPlugin) dump(dir, event string, args ...interface{}) { case UpdateContainers: // post-config outgoing UpdateContainers if dir == out { if len(args) != 1 { - nri.Error("%s %s ", dir, event, len(args)) + nri.Errorf("%s %s ", dir, event, len(args)) return } - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) p.dumpDetails(dir, event, args[0]) } else { if len(args) != 1 { - nri.Error("%s %s ", dir, event, len(args)) + nri.Errorf("%s %s ", dir, event, len(args)) return } err := args[0] if err == nil { - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) return } - nri.Error("%s %s FAILED: %v", dir, event, err.(error)) + nri.Errorf("%s %s FAILED: %v", dir, event, err.(error)) } case Configure: if dir == in { if len(args) != 2 { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, len(args)) return } runtime, ok := args[0].(string) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1]) return } version, ok := args[1].(string) if !ok { - nri.Error("%s %s ", + nri.Errorf("%s %s ", dir, event, args[0], args[1]) return } - nri.Info("%s %s, runtime %s %s", dir, event, runtime, version) + nri.Infof("%s %s, runtime %s %s", dir, event, runtime, version) } else { - nri.Info("%s %s", dir, event) + nri.Infof("%s %s", dir, event) } case Synchronize: if dir == in { if len(args) != 2 { - nri.Error("%s %s 127), got nil") + t.Errorf("expected error for int8 base value 200 (> 127), got nil") } }) t.Run("uint8", func(t *testing.T) { var v uint8 if err := parseVal(t, "200", &v); err == nil { - t.Error("expected error for uint8 base value 200 (> 127 signed), got nil") + t.Errorf("expected error for uint8 base value 200 (> 127 signed), got nil") } }) // int16 / uint16: ParseInt bitSize=16 accepts only –32768..32767. t.Run("int16", func(t *testing.T) { var v int16 if err := parseVal(t, "40000", &v); err == nil { - t.Error("expected error for int16 base value 40000 (> 32767), got nil") + t.Errorf("expected error for int16 base value 40000 (> 32767), got nil") } }) t.Run("uint16", func(t *testing.T) { var v uint16 if err := parseVal(t, "40000", &v); err == nil { - t.Error("expected error for uint16 base value 40000 (> 32767 signed), got nil") + t.Errorf("expected error for uint16 base value 40000 (> 32767 signed), got nil") } }) }) @@ -381,21 +381,21 @@ func TestParseNumericUnits_Negative(t *testing.T) { t.Run("non_numeric_base", func(t *testing.T) { var v int64 if err := parseVal(t, "abc", &v); err == nil { - t.Error("expected error for non-numeric value, got nil") + t.Errorf("expected error for non-numeric value, got nil") } }) // Non-numeric base with a valid unit. t.Run("non_numeric_base_with_unit", func(t *testing.T) { var v int64 if err := parseVal(t, "abc k", &v); err == nil { - t.Error("expected error for non-numeric base with unit, got nil") + t.Errorf("expected error for non-numeric base with unit, got nil") } }) // Three whitespace-separated tokens are rejected by splitNumericAndUnit. t.Run("three_tokens", func(t *testing.T) { var v int64 if err := parseVal(t, "1 k extra", &v); err == nil { - t.Error("expected error for three-token input, got nil") + t.Errorf("expected error for three-token input, got nil") } }) }) diff --git a/pkg/sysfs/system.go b/pkg/sysfs/system.go index 19a948394..394b39d55 100644 --- a/pkg/sysfs/system.go +++ b/pkg/sysfs/system.go @@ -406,7 +406,7 @@ func (sys *system) Discover(flags DiscoveryFlag) error { if (sys.flags & DiscoverSst) != 0 { if err := sys.discoverSst(); err != nil { // Just consider SST unsupported if our detection fails for some reason - sys.Warn("%v", err) + sys.Warnf("%v", err) } } @@ -438,34 +438,34 @@ func (sys *system) Discover(flags DiscoveryFlag) error { } if sys.DebugEnabled() { - sys.Debug("CPUs:") - sys.Debug(" - possible: %s", sys.PossibleCPUs()) - sys.Debug(" - present: %s", sys.PresentCPUs()) - sys.Debug(" - online: %s", sys.OnlineCPUs()) - sys.Debug(" - offline: %s", sys.OfflineCPUs()) - sys.Debug(" - isolated: %s", sys.IsolatedCPUs()) + sys.Debugf("CPUs:") + sys.Debugf(" - possible: %s", sys.PossibleCPUs()) + sys.Debugf(" - present: %s", sys.PresentCPUs()) + sys.Debugf(" - online: %s", sys.OnlineCPUs()) + sys.Debugf(" - offline: %s", sys.OfflineCPUs()) + sys.Debugf(" - isolated: %s", sys.IsolatedCPUs()) for kind, name := range coreKindNames { if cpus := sys.CoreKindCPUs(kind); !cpus.IsEmpty() { - sys.Debug(" - %8s: %s", name, sys.CoreKindCPUs(kind)) + sys.Debugf(" - %8s: %s", name, sys.CoreKindCPUs(kind)) } } for _, id := range sys.PackageIDs() { pkg := sys.packages[id] - sys.Info("package #%d:", id) - sys.Debug(" cpus: %s", pkg.cpus) - sys.Debug(" nodes: %s", pkg.nodes) - sys.Debug(" dies: %s", pkg.dies) + sys.Infof("package #%d:", id) + sys.Debugf(" cpus: %s", pkg.cpus) + sys.Debugf(" nodes: %s", pkg.nodes) + sys.Debugf(" dies: %s", pkg.dies) for _, die := range pkg.DieIDs() { - sys.Debug(" die #%v nodes: %v", die, pkg.DieNodeIDs(die)) - sys.Debug(" die #%v cpus: %s", die, pkg.DieCPUSet(die).String()) + sys.Debugf(" die #%v nodes: %v", die, pkg.DieNodeIDs(die)) + sys.Debugf(" die #%v cpus: %s", die, pkg.DieCPUSet(die).String()) for _, cluster := range pkg.DieClusterIDs(die) { - sys.Debug(" die #%v cluster #%v cpus: %s", die, cluster, + sys.Debugf(" die #%v cluster #%v cpus: %s", die, cluster, pkg.DieClusterCPUSet(die, cluster).String()) } for _, cluster := range pkg.LogicalDieClusterIDs(die) { - sys.Debug(" die #%v logical cluster #%v cpus: %s", die, cluster, + sys.Debugf(" die #%v logical cluster #%v cpus: %s", die, cluster, pkg.LogicalDieClusterCPUSet(die, cluster).String()) } } @@ -473,33 +473,33 @@ func (sys *system) Discover(flags DiscoveryFlag) error { for _, id := range sys.NodeIDs() { node := sys.nodes[id] - sys.Debug("node #%d:", id) - sys.Debug(" cpus: %s", node.cpus) - sys.Debug(" distance: %v", node.distance) - sys.Debug(" package: #%d", node.pkg) - sys.Debug(" die: #%d", node.die) + sys.Debugf("node #%d:", id) + sys.Debugf(" cpus: %s", node.cpus) + sys.Debugf(" distance: %v", node.distance) + sys.Debugf(" package: #%d", node.pkg) + sys.Debugf(" die: #%d", node.die) } for _, id := range sys.CPUIDs() { cpu := sys.cpus[id] - sys.Debug("CPU #%d:", id) - sys.Debug(" pkg: %d", cpu.pkg) - sys.Debug(" die: %d", cpu.die) - sys.Debug(" cluster: %d", cpu.cluster) - sys.Debug(" node: %d", cpu.node) - sys.Debug(" core: %d (%s)", cpu.core, cpu.coreKind) - sys.Debug(" threads: %s", cpu.threads) - sys.Debug(" base freq: %d", cpu.freq.Base) - sys.Debug(" freq: %d - %d", cpu.freq.Min, cpu.freq.Max) - sys.Debug(" epp: %d", cpu.epp) + sys.Debugf("CPU #%d:", id) + sys.Debugf(" pkg: %d", cpu.pkg) + sys.Debugf(" die: %d", cpu.die) + sys.Debugf(" cluster: %d", cpu.cluster) + sys.Debugf(" node: %d", cpu.node) + sys.Debugf(" core: %d (%s)", cpu.core, cpu.coreKind) + sys.Debugf(" threads: %s", cpu.threads) + sys.Debugf(" base freq: %d", cpu.freq.Base) + sys.Debugf(" freq: %d - %d", cpu.freq.Min, cpu.freq.Max) + sys.Debugf(" epp: %d", cpu.epp) for idx, c := range cpu.caches { - sys.Debug(" cache #%d:", idx) - sys.Debug(" id: %d", c.id) - sys.Debug(" level: %d", c.level) - sys.Debug(" kind: %s", c.kind) - sys.Debug(" size: %dK", c.size/1024) - sys.Debug(" cpus: %s", c.SharedCPUSet().String()) + sys.Debugf(" cache #%d:", idx) + sys.Debugf(" id: %d", c.id) + sys.Debugf(" level: %d", c.level) + sys.Debugf(" kind: %s", c.kind) + sys.Debugf(" size: %dK", c.size/1024) + sys.Debugf(" cpus: %s", c.SharedCPUSet().String()) } } } @@ -856,7 +856,7 @@ func (sys *system) Isolated() cpuset.CPUSet { func (sys *system) NodeHintToCPUs(nodes string) string { mset, err := cpuset.Parse(nodes) if err != nil { - log.Error("failed to resolve nodes %q to CPUs: %v", nodes, err) + log.Errorf("failed to resolve nodes %q to CPUs: %v", nodes, err) return "" } @@ -881,29 +881,29 @@ func (sys *system) discoverCPUs() error { base := filepath.Join(sys.path, sysfsCPUPath) _, err := readSysfsEntry(base, "possible", &sys.possibleCPUs, ",") if err != nil { - sys.Error("failed to get set of possible cpus: %v", err) + sys.Errorf("failed to get set of possible cpus: %v", err) } _, err = readSysfsEntry(base, "present", &sys.presentCPUs, ",") if err != nil { - sys.Error("failed to get set of present cpus: %v", err) + sys.Errorf("failed to get set of present cpus: %v", err) } _, err = readSysfsEntry(base, "online", &sys.onlineCPUs, ",") if err != nil { - sys.Error("failed to get set of online cpus: %v", err) + sys.Errorf("failed to get set of online cpus: %v", err) } _, err = readSysfsEntry(base, "isolated", &sys.isolatedCPUs, ",") if err != nil { - sys.Error("failed to get set of isolated cpus: %v", err) + sys.Errorf("failed to get set of isolated cpus: %v", err) } sys.coreKindCPUs = make(map[CoreKind]idset.IDSet) for kind, name := range coreKindEnvOverrides { if override := os.Getenv(name); override != "" { - log.Warn("using CPU core kind environment override (%s=%s)...", name, override) + log.Warnf("using CPU core kind environment override (%s=%s)...", name, override) cpus, err := cpuset.Parse(override) if err != nil { return fmt.Errorf("failed to parse %s env. override %q: %v", kind, override, err) @@ -919,7 +919,7 @@ func (sys *system) discoverCPUs() error { cpus := idset.NewIDSet() _, err = readSysfsEntry(sys.path, entry, &cpus, ",") if err != nil { - sys.Error("failed to get set of %s cpus: %v", kind, err) + sys.Errorf("failed to get set of %s cpus: %v", kind, err) if kind == PerformanceCore { cpus = sys.onlineCPUs.Clone() } @@ -1415,9 +1415,9 @@ func (sys *system) discoverNodes() error { } cpuNodes := cpuset.New(cpuNodesSlice...) - sys.Info("NUMA nodes with CPUs: %s", cpuNodes.String()) - sys.Info("NUMA nodes with (any) memory: %s", memoryNodes.String()) - sys.Info("NUMA nodes with normal memory: %s", normalMemNodes.String()) + sys.Infof("NUMA nodes with CPUs: %s", cpuNodes.String()) + sys.Infof("NUMA nodes with (any) memory: %s", memoryNodes.String()) + sys.Infof("NUMA nodes with normal memory: %s", normalMemNodes.String()) noMemNodes := onlineNodes.Difference(memoryNodes) dramNodes := cpuNodes.Clone() @@ -1464,14 +1464,14 @@ func (sys *system) discoverNodes() error { return fmt.Errorf("not able to determine system special memory types") } if mem.MemTotal < dramAvg { - sys.Info("node %d has HBM memory", node.id) + sys.Infof("node %d has HBM memory", node.id) node.memoryType = MemoryTypeHBM } else { - sys.Info("node %d has PMEM memory", node.id) + sys.Infof("node %d has PMEM memory", node.id) node.memoryType = MemoryTypePMEM } } else if _, ok := dramNodeIds[node.id]; ok { - sys.Info("node %d has DRAM memory", node.id) + sys.Infof("node %d has DRAM memory", node.id) node.memoryType = MemoryTypeDRAM } else { return fmt.Errorf("unknown memory type for node %v (pmem nodes: %s, dram nodes: %s)", node, pmemOrHbmNodes, dramNodes) @@ -1836,7 +1836,7 @@ func (sys *system) discoverPackages() error { func (sys *system) discoverSst() error { if !sst.SstSupported() { - sys.Info("Speed Select Technology (SST) support not detected") + sys.Infof("Speed Select Technology (SST) support not detected") return nil } @@ -2055,10 +2055,10 @@ func (sys *system) discoverCacheFromOverrides(cpu *cpu) (bool, error) { return false, nil } if cacheEnvOverrides == nil { - sys.Debug("parsing cache overrides from %s=%q", cacheEnvOverridesVar, cacheEnvOverridesJson) + sys.Debugf("parsing cache overrides from %s=%q", cacheEnvOverridesVar, cacheEnvOverridesJson) ceo, err := parseCpuCacheOverrides(cacheEnvOverridesJson) if err != nil { - sys.Error("failed to parse cache overrides: %v", err) + sys.Errorf("failed to parse cache overrides: %v", err) return false, err } // cpu.caches must be ordered by cache level, the lowest first. @@ -2074,7 +2074,7 @@ func (sys *system) discoverCacheFromOverrides(cpu *cpu) (bool, error) { if caches, ok := cacheEnvOverrides[cpu.id]; ok { cpu.caches = make([]*Cache, len(caches)) for i, c := range caches { - sys.Debug("cpu %d cache override %+v", cpu.id, *c) + sys.Debugf("cpu %d cache override %+v", cpu.id, *c) cpu.caches[i] = sys.saveCache(c) } return true, nil diff --git a/pkg/udev/doc.go b/pkg/udev/doc.go index e433d85dc..cb47a4311 100644 --- a/pkg/udev/doc.go +++ b/pkg/udev/doc.go @@ -121,7 +121,7 @@ package udev // filter[strings.ToUpper(kv[0])] = kv[1] // } // if len(filter) > 0 { -// log.Info("using parsed filter: %v", filter) +// log.Infof("using parsed filter: %v", filter) // filters = append(filters, filter) // } // } diff --git a/pkg/udev/reader.go b/pkg/udev/reader.go index 3e6e84c42..dbedc8b6d 100644 --- a/pkg/udev/reader.go +++ b/pkg/udev/reader.go @@ -93,7 +93,7 @@ func (r *Reader) Read(p []byte) (int, error) { // TODO(klihub): make this controllable using an option ? if err == syscall.ENOBUFS { - log.Warn("udev ran out of buffer space (was dropping events)") + log.Warnf("udev ran out of buffer space (was dropping events)") err = nil } diff --git a/scripts/udev-monitor/udev-monitor.go b/scripts/udev-monitor/udev-monitor.go index bd513176d..884813a4f 100644 --- a/scripts/udev-monitor/udev-monitor.go +++ b/scripts/udev-monitor/udev-monitor.go @@ -63,7 +63,7 @@ func parseFilters() []map[string]string { filter[strings.ToUpper(kv[0])] = kv[1] } if len(filter) > 0 { - log.Info("using parsed filter: %v", filter) + log.Infof("using parsed filter: %v", filter) filters = append(filters, filter) } } From b4fc03ff433558f3bbf58eb5d6496e5f6a3d1999 Mon Sep 17 00:00:00 2001 From: Krisztian Litkey Date: Thu, 16 Apr 2026 10:49:59 +0300 Subject: [PATCH 4/4] pkg,cmd: fix linting errors. Signed-off-by: Krisztian Litkey --- cmd/plugins/balloons/policy/balloons-policy.go | 18 +++++++++--------- pkg/agent/agent.go | 4 ++-- pkg/resmgr/cache/container.go | 18 ++++++++---------- pkg/resmgr/control/e2e-test/e2e-test.go | 3 +-- pkg/resmgr/policy/policy.go | 4 ++-- 5 files changed, 22 insertions(+), 25 deletions(-) diff --git a/cmd/plugins/balloons/policy/balloons-policy.go b/cmd/plugins/balloons/policy/balloons-policy.go index a1de819f5..a2f31323f 100644 --- a/cmd/plugins/balloons/policy/balloons-policy.go +++ b/cmd/plugins/balloons/policy/balloons-policy.go @@ -318,7 +318,7 @@ func (p *balloons) AllocateResources(c cache.Container) error { } p.assignContainer(c, bln) if log.DebugEnabled() { - log.Debugf(p.dumpBalloon(bln)) + log.Debugf("%s", p.dumpBalloon(bln)) } return nil @@ -333,7 +333,7 @@ func (p *balloons) ReleaseResources(c cache.Container) error { if bln := p.balloonByContainer(c); bln != nil { p.dismissContainer(c, bln) if log.DebugEnabled() { - log.Debugf(p.dumpBalloon(bln)) + log.Debugf("%s", p.dumpBalloon(bln)) } if bln.ContainerCount() == 0 { // Deflate the balloon completely before @@ -1023,7 +1023,7 @@ func (p *balloons) newCompositeBalloon(blnDef *BalloonDef, confCpus bool, freeIn if confCpus { if err := p.useCpuClass(bln); err != nil { deleteComponentBlns() - log.Errorf("failed to apply CPU configuration to new composite balloon %s[%d] (cpus: %s): %w", + log.Errorf("failed to apply CPU configuration to new composite balloon %s[%d] (cpus: %s): %v", blnDef.Name, bln.Instance, bln.Cpus, err) return nil, err } @@ -1108,7 +1108,7 @@ func (p *balloons) newBalloon(blnDef *BalloonDef, confCpus bool) (*Balloon, erro bln.Mems = p.closestMems(bln.Cpus) if confCpus { if err = p.useCpuClass(bln); err != nil { - log.Errorf("failed to apply CPU configuration to new balloon %s[%d] (cpus: %s): %w", blnDef.Name, freeInstance, cpus, err) + log.Errorf("failed to apply CPU configuration to new balloon %s[%d] (cpus: %s): %v", blnDef.Name, freeInstance, cpus, err) return nil, err } } @@ -1321,7 +1321,7 @@ func (p *balloons) allocateBalloonOfDef(blnDef *BalloonDef, c cache.Container) ( for _, fillMethod := range fillChain { blns, err := p.fillableBalloonInstances(blnDef, fillMethod, c) if err != nil { - log.Debugf("fill method %q prevents allocation: %w", fillMethod, err) + log.Debugf("fill method %q prevents allocation: %v", fillMethod, err) return nil, err } if len(blns) == 0 { @@ -1975,7 +1975,7 @@ func (p *balloons) resizeCompositeBalloon(bln *Balloon, newMilliCpus int) error } p.forgetCpuClass(bln) // reset CPU classes in balloon's old CPUs bln.Cpus = blnCpus - log.Debugf("- resize composite ballooon successful: %s, freecpus: %#s", bln, p.freeCpus) + log.Debugf("- resize composite ballooon successful: %s, freecpus: %s", bln, p.freeCpus) p.updatePinning(bln) if err := p.useCpuClass(bln); err != nil { // set CPU classes in balloon's new CPUs log.Warnf("failed to apply CPU class to balloon %s: %v", bln.PrettyName(), err) @@ -2045,7 +2045,7 @@ func (p *balloons) resizeBalloon(bln *Balloon, newMilliCpus int) error { log.Debugf("- released, changed cpus: balloon from %q to %q, free from %q to %q", oldBlnCpus, bln.Cpus, oldFreeCpus, p.freeCpus) p.updatePinning(p.shareIdleCpus(removeFromCpus, cpuset.New())...) } - log.Debugf("- resize successful: %s, freecpus: %#s", bln, p.freeCpus) + log.Debugf("- resize successful: %s, freecpus: %s", bln, p.freeCpus) p.updatePinning(bln) return nil } @@ -2265,13 +2265,13 @@ func (p *balloons) pinCpuMem(c cache.Container, cpus cpuset.CPUSet, mems idset.I } if pinMemory { if c.PreserveMemoryResources() { - log.Debugf(" - preserving %s pinning to memory %q", c.PrettyName, c.GetCpusetMems()) + log.Debugf(" - preserving %s pinning to memory %q", c.PrettyName(), c.GetCpusetMems()) preserveMems, err := parseIDSet(c.GetCpusetMems()) if err != nil { log.Errorf("failed to parse CpusetMems: %v", err) } else { zone := p.allocMem(c, preserveMems, 0, true) - log.Debugf(" - allocated preserved memory %s", c.PrettyName, zone) + log.Debugf(" - allocated %s to preserved memory %s", c.PrettyName(), zone) c.SetCpusetMems(zone.MemsetString()) } } else { diff --git a/pkg/agent/agent.go b/pkg/agent/agent.go index d001043a3..ac0f8a649 100644 --- a/pkg/agent/agent.go +++ b/pkg/agent/agent.go @@ -292,12 +292,12 @@ func (a *Agent) configure(newConfig metav1.Object) { log.Infof("enabling NRT client") cfg, err := a.getRESTConfig() if err != nil { - log.Errorf("failed to setup NRT client: %w", err) + log.Errorf("failed to setup NRT client: %v", err) break } cli, err := nrtapi.NewForConfigAndClient(cfg, a.httpCli) if err != nil { - log.Errorf("failed to setup NRT client: %w", err) + log.Errorf("failed to setup NRT client: %v", err) break } a.nrtCli = cli diff --git a/pkg/resmgr/cache/container.go b/pkg/resmgr/cache/container.go index b0982ca09..9696a0ded 100644 --- a/pkg/resmgr/cache/container.go +++ b/pkg/resmgr/cache/container.go @@ -146,16 +146,15 @@ func checkAllowedAndDeniedPaths(hostPath string, allowPathList, denyPathList *Pa if denyPathList.Type == GlobMatch { matched, err = filepath.Match(path, hostPath) + if err != nil { + log.Errorf("Malformed pattern \"%s\"", path) + return false + } } else { // Note that match requires pattern to match all of name, not just a substring. matched = strings.HasPrefix(hostPath, path) } - if err != nil { - log.Errorf("Malformed pattern \"%s\"", matched) - return false - } - if matched { log.Debugf("Deny match, removing %s from hints", path) denied = true @@ -171,16 +170,15 @@ func checkAllowedAndDeniedPaths(hostPath string, allowPathList, denyPathList *Pa if allowPathList.Type == GlobMatch { matched, err = filepath.Match(path, hostPath) + if err != nil { + log.Errorf("Malformed pattern \"%s\"", path) + return denied + } } else { // Note that match requires pattern to match all of name, not just a substring. matched = strings.HasPrefix(hostPath, path) } - if err != nil { - log.Errorf("Malformed pattern \"%s\"", matched) - return denied - } - if matched { log.Debugf("Allow match, adding %s to hints", path) return false diff --git a/pkg/resmgr/control/e2e-test/e2e-test.go b/pkg/resmgr/control/e2e-test/e2e-test.go index 93cd882d9..de9076c14 100644 --- a/pkg/resmgr/control/e2e-test/e2e-test.go +++ b/pkg/resmgr/control/e2e-test/e2e-test.go @@ -69,8 +69,7 @@ func getE2ETestController() *testctl { // Start initializes the controller for enforcing decisions. func (ctl *testctl) Start(cache cache.Cache, cfg *cfgapi.Config) (bool, error) { - log.Debugf("Start called (with test APIs %s)", - map[bool]string{false: "disabled", true: "enabled"}) + log.Debugf("Start called (with test APIs %v)", enableTestAPIs) if !enableTestAPIs { return false, nil diff --git a/pkg/resmgr/policy/policy.go b/pkg/resmgr/policy/policy.go index 72dcb6aca..ceaff7934 100644 --- a/pkg/resmgr/policy/policy.go +++ b/pkg/resmgr/policy/policy.go @@ -307,7 +307,7 @@ func (p *policy) HandleEvent(e *events.Policy) (bool, error) { // ExportResourceData exports/updates resource data for the container. func (p *policy) ExportResourceData(c cache.Container) { - var buf bytes.Buffer + buf := &bytes.Buffer{} data := p.active.ExportResourceData(c) keys := []string{} @@ -318,7 +318,7 @@ func (p *policy) ExportResourceData(c cache.Container) { for _, key := range keys { value := data[key] - if _, err := buf.WriteString(fmt.Sprintf("%s=%q\n", key, value)); err != nil { + if _, err := fmt.Fprintf(buf, "%s=%q\n", key, value); err != nil { log.Errorf("container %s: failed to export resource data (%s=%q)", c.PrettyName(), key, value) buf.Reset()