Skip to content

Commit

Permalink
[YUNIKORN-1985] Fix possible log spew in application object in tryAll…
Browse files Browse the repository at this point in the history
…ocate
  • Loading branch information
brandboat committed Oct 25, 2023
1 parent 418714d commit 6eceecf
Show file tree
Hide file tree
Showing 5 changed files with 171 additions and 1 deletion.
1 change: 1 addition & 0 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,7 @@ require (
go.uber.org/multierr v1.6.0 // indirect
golang.org/x/sys v0.12.0 // indirect
golang.org/x/text v0.13.0 // indirect
golang.org/x/time v0.3.0 // indirect
google.golang.org/genproto v0.0.0-20230410155749-daa745c078e1 // indirect
google.golang.org/protobuf v1.30.0 // indirect
gopkg.in/check.v1 v1.0.0-20200227125254-8fa46927fb4f // indirect
Expand Down
2 changes: 2 additions & 0 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -288,6 +288,8 @@ golang.org/x/text v0.13.0/go.mod h1:TvPlkZtksWOMsz7fbANvkp4WM8x/WCo/om8BMLbz+aE=
golang.org/x/time v0.0.0-20181108054448-85acf8d2951c/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.0.0-20190308202827-9d24e82272b4/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.0.0-20191024005414-555d28b269f0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.3.0 h1:rg5rLMjNzMS1RkNLzCG38eapWhnYLFYXDXj2gOlr8j4=
golang.org/x/time v0.3.0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/tools v0.13.0/go.mod h1:HvlwmtVNQAhOuCjW7xxvovg8wbNq7LwfXh/k7wXUl58=
golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
Expand Down
89 changes: 89 additions & 0 deletions pkg/log/rate_limited_logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,89 @@
/*
Licensed to the Apache Software Foundation (ASF) under one
or more contributor license agreements. See the NOTICE file
distributed with this work for additional information
regarding copyright ownership. The ASF licenses this file
to you under the Apache License, Version 2.0 (the
"License"); you may not use this file except in compliance
with the License. You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/

package log

import (
"time"

"go.uber.org/zap"
"golang.org/x/time/rate"
)

type rateLimitedLogger struct {
logger *zap.Logger
limiter *rate.Limiter
}

// RateLimitedLogger provides a logger that only logs once within a specified duration
func RateLimitedLog(handle *LoggerHandle, every time.Duration) *rateLimitedLogger {
return &rateLimitedLogger{
logger: Log(handle),
limiter: rate.NewLimiter(rate.Every(every), 1),
}
}

// visible for testing
func TestingRateLimitedLog(logger *zap.Logger, every time.Duration) *rateLimitedLogger {
return &rateLimitedLogger{
logger: logger,
limiter: rate.NewLimiter(rate.Every(every), 1),
}
}

func (rl *rateLimitedLogger) Debug(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Debug(msg, fields...)
}
}

func (rl *rateLimitedLogger) Info(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Info(msg, fields...)
}
}

func (rl *rateLimitedLogger) Warn(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Warn(msg, fields...)
}
}

func (rl *rateLimitedLogger) Error(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Error(msg, fields...)
}
}

func (rl *rateLimitedLogger) DPanic(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.DPanic(msg, fields...)
}
}

func (rl *rateLimitedLogger) Panic(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Panic(msg, fields...)
}
}

func (rl *rateLimitedLogger) Fatal(msg string, fields ...zap.Field) {
if rl.limiter.Allow() {
rl.logger.Fatal(msg, fields...)
}
}
76 changes: 76 additions & 0 deletions pkg/log/rate_limited_logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
/*
Licensed to the Apache Software Foundation (ASF) under one
or more contributor license agreements. See the NOTICE file
distributed with this work for additional information
regarding copyright ownership. The ASF licenses this file
to you under the Apache License, Version 2.0 (the
"License"); you may not use this file except in compliance
with the License. You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/

package log

import (
"encoding/json"
"fmt"
"os"
"testing"
"time"

"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"gotest.tools/v3/assert"
)

type logMessage struct {
Level string `json:"level"`
Message string `json:"msg"`
}

func TestRateLimitedLog(t *testing.T) {
zapLogger, logFile := createZapTestLogger()
logger := TestingRateLimitedLog(zapLogger, time.Minute)

// this won't last over one minute, assert there is only one record in log file
for i := 0; i < 10000; i++ {
logger.Info("YuniKorn")
}

content, err := os.ReadFile(logFile)
if err != nil {
fmt.Printf("Failed reading file: %s", err)
}
var logMessage logMessage

Check failure on line 51 in pkg/log/rate_limited_logger_test.go

View workflow job for this annotation

GitHub Actions / build

shadow: declaration of "logMessage" shadows declaration at line 33 (govet)
err = json.Unmarshal(content, &logMessage)
assert.NilError(t, err, "failed to unmarshal logMessage from log file: %s", content)
assert.Equal(t, zapcore.InfoLevel.String(), logMessage.Level)
assert.Equal(t, "YuniKorn", logMessage.Message)
}

// create zap logger that log in json format and output to temp file
func createZapTestLogger() (*zap.Logger, string) {
logDir, err := os.MkdirTemp("", "log*")
if err != nil {
panic(err)
}
logFile := fmt.Sprintf("%s/log.stdout", logDir)
outputPaths := []string{logFile}
zapConfig := zap.NewProductionConfig()
zapConfig.Encoding = "json"
zapConfig.OutputPaths = outputPaths

zapLogger, err := zapConfig.Build()
if err != nil {
panic(err)
}

return zapLogger, logFile
}
4 changes: 3 additions & 1 deletion pkg/scheduler/objects/application.go
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,8 @@ var (
defaultPlaceholderTimeout = 15 * time.Minute
)

var rateLimitedLog = log.RateLimitedLog(log.SchedApplication, time.Second)

const (
Soft string = "Soft"
Hard string = "Hard"
Expand Down Expand Up @@ -990,7 +992,7 @@ func (sa *Application) tryAllocate(headRoom *resources.Resource, preemptionDelay
// the iterator might not have the node we need as it could be reserved, or we have not added it yet
node := getNodeFn(requiredNode)
if node == nil {
log.Log(log.SchedApplication).Warn("required node is not found (could be transient)",
rateLimitedLog.Warn("required node is not found (could be transient)",
zap.String("application ID", sa.ApplicationID),
zap.String("allocationKey", request.GetAllocationKey()),
zap.String("required node", requiredNode))
Expand Down

0 comments on commit 6eceecf

Please sign in to comment.