Skip to content

Commit

Permalink
unify logging to logrus in calico-apiserver (#9600)
Browse files Browse the repository at this point in the history
1. change all logging statements inside calico-apiserver code base
to use logrus.
used within calico-apiserver will log with logrus.
3. fix some log levels to better reflect of the log severity.
  • Loading branch information
ti-afra authored Dec 17, 2024
1 parent a2e3864 commit 1e7b062
Show file tree
Hide file tree
Showing 15 changed files with 299 additions and 102 deletions.
8 changes: 4 additions & 4 deletions apiserver/cmd/apiserver/apiserver.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,11 +22,11 @@ import (
"os"
"runtime"

"github.com/sirupsen/logrus"
"k8s.io/apiserver/pkg/features"
"k8s.io/apiserver/pkg/util/feature"
"k8s.io/component-base/cli"
"k8s.io/component-base/logs"
"k8s.io/klog/v2"

"github.com/projectcalico/calico/apiserver/cmd/apiserver/server"
)
Expand All @@ -42,7 +42,7 @@ func main() {
string(features.ConsistentListFromCache): false,
})
if err != nil {
klog.Errorf("Error setting feature gates: %v.", err)
logrus.Errorf("Error setting feature gates: %v.", err)
logs.FlushLogs()
os.Exit(1)
}
Expand All @@ -53,13 +53,13 @@ func main() {

err = server.Version()
if err != nil {
klog.Errorf("Error printing version info: %v.", err)
logrus.Errorf("Error printing version info: %v.", err)
logs.FlushLogs()
}

cmd, _, err := server.NewCommandStartCalicoServer(os.Stdout)
if err != nil {
klog.Errorf("Error creating server: %v", err)
logrus.Errorf("Error creating server: %v", err)
logs.FlushLogs()
os.Exit(1)
}
Expand Down
134 changes: 134 additions & 0 deletions apiserver/cmd/apiserver/server/logging.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,134 @@
package server

import (
"fmt"
"os"
"strconv"

"github.com/go-logr/logr"
"github.com/sirupsen/logrus"
"k8s.io/component-base/logs"
"k8s.io/klog/v2"

"github.com/projectcalico/calico/libcalico-go/lib/logutils"
)

// logrusLevel sets LOG_LEVEL and if not defined will set it based on klog verbosity
// v=0 --> ERROR
// v=1 --> WARN
// v=2 --> INFO
// v=3-6 --> DEBUG
// v=7-9 --> TRACE
func logrusLevel() logrus.Level {
if env := os.Getenv("LOG_LEVEL"); env != "" {
return logutils.SafeParseLogLevel(env)
}
if klog.V(0).Enabled() && !klog.V(1).Enabled() {
return logrus.ErrorLevel
}
if klog.V(1).Enabled() && !klog.V(2).Enabled() {
return logrus.WarnLevel
}
if klog.V(2).Enabled() && !klog.V(3).Enabled() {
return logrus.InfoLevel
}
if (klog.V(3).Enabled() || klog.V(4).Enabled() || klog.V(5).Enabled() || klog.V(6).Enabled()) && !klog.V(7).Enabled() {
return logrus.DebugLevel
}

// klog.V(7).Enabled() || klog.V(8).Enabled() || klog.V(9).Enabled()
return logrus.TraceLevel
}

// verbosityLevel sets VERBOSITY based on LOG_LEVEL
// ERROR, FATAL --> v=0
// WARN --> v=1
// INFO --> v=2
// DEBUG --> v=3:6
// TRACE --> v=7 and above (i.e., show everything)
func logLevelToVerbosityLevel() string {
switch logrus.GetLevel() {
case logrus.TraceLevel:
return "20"
case logrus.DebugLevel:
return "6"
case logrus.InfoLevel:
return "2"
case logrus.WarnLevel:
return "1"
case logrus.ErrorLevel:
return "0"
case logrus.FatalLevel:
return "0"
}
return "2" // return default "2" for info.
}

// CustomLogger is a wrapper around logrus to forward klog messages
type logrusKlog struct {
logger *logrus.Entry
}

func (l logrusKlog) Init(info logr.RuntimeInfo) {
l.logger.Logger.SetLevel(logrusLevel())
}

func (l logrusKlog) Enabled(level int) bool {
l.logger.Trace("loglevel: ", logLevelToVerbosityLevel())
logLevel, err := strconv.ParseInt(logLevelToVerbosityLevel(), 10, 64)
if err != nil {
l.logger.Error("failed to parseInt log level verbosity: ", logLevelToVerbosityLevel())
return false
}
return int64(level) == logLevel
}

func toLogrusFields(keysAndValues ...interface{}) logrus.Fields {
fields := logrus.Fields{}
for i := 0; i < len(keysAndValues); i += 2 {
key := fmt.Sprintf("%v", keysAndValues[i])
fields[key] = keysAndValues[i+1]
}
return fields
}

func (l logrusKlog) Info(level int, msg string, keysAndValues ...any) {
l.logger.WithFields(toLogrusFields(keysAndValues...)).Info(msg)
}

func (l logrusKlog) Error(err error, msg string, keysAndValues ...any) {
l.logger.WithFields(toLogrusFields(keysAndValues...)).WithError(err).Error(msg)
}

func (l logrusKlog) WithName(name string) logr.LogSink {
// do nothing
return l
}

func (l logrusKlog) WithValues(keysAndValues ...any) logr.LogSink {
// do nothing
return l
}

func configureLogging() {
// set logrus log-level for tigera-apiserver logging
logrus.SetLevel(logrusLevel())

// create a logrus logger to be used by klog
logrusLogger := logrus.New().WithField("klog-logger", "tigera-apiserver")
logrusLogger.Logger.SetLevel(logrusLevel())

logrusLoggerWrapper := logrusKlog{logger: logrusLogger}

klogLogger := logr.New(logrusLoggerWrapper)
klog.SetLogger(klogLogger)

// set klog verbosity for libraries used in tigera-apiserver
msg, err := logs.GlogSetter(logLevelToVerbosityLevel())
if err != nil {
logrus.Errorf("Failed to set glog setter: %v", err)
}
if err == nil && msg != "" {
logrus.Tracef("Successfully set glog setter: %s", msg)
}
}
79 changes: 79 additions & 0 deletions apiserver/cmd/apiserver/server/logging_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,79 @@
package server

import (
"testing"

. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
"github.com/sirupsen/logrus"
"k8s.io/component-base/logs"
)

func TestLogLevel(t *testing.T) {
RegisterFailHandler(Fail)
RunSpecs(t, "Logging Suite")
}

var _ = Describe("", func() {
It("test logrus log level calculated with different verbosity values", func() {
_, err := logs.GlogSetter("0")
Expect(logrusLevel()).To(Equal(logrus.ErrorLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("1")
Expect(logrusLevel()).To(Equal(logrus.WarnLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("2")
Expect(logrusLevel()).To(Equal(logrus.InfoLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("3")
Expect(logrusLevel()).To(Equal(logrus.DebugLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("4")
Expect(logrusLevel()).To(Equal(logrus.DebugLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("5")
Expect(logrusLevel()).To(Equal(logrus.DebugLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("6")
Expect(logrusLevel()).To(Equal(logrus.DebugLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("7")
Expect(logrusLevel()).To(Equal(logrus.TraceLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("8")
Expect(logrusLevel()).To(Equal(logrus.TraceLevel))
Expect(err).To(BeNil())

_, err = logs.GlogSetter("9")
Expect(logrusLevel()).To(Equal(logrus.TraceLevel))
Expect(err).To(BeNil())
})

It("test verbosity values calculated from various logrus log level", func() {
logrus.SetLevel(logrus.TraceLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("20"))

logrus.SetLevel(logrus.DebugLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("6"))

logrus.SetLevel(logrus.InfoLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("2"))

logrus.SetLevel(logrus.WarnLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("1"))

logrus.SetLevel(logrus.ErrorLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("0"))

logrus.SetLevel(logrus.FatalLevel)
Expect(logLevelToVerbosityLevel()).To(Equal("0"))
})
})
4 changes: 2 additions & 2 deletions apiserver/cmd/apiserver/server/options.go
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@ import (
"time"

"github.com/projectcalico/api/pkg/openapi"
"github.com/sirupsen/logrus"
"github.com/spf13/pflag"
utilerrors "k8s.io/apimachinery/pkg/util/errors"
"k8s.io/apiserver/pkg/authorization/authorizerfactory"
Expand All @@ -35,7 +36,6 @@ import (
genericoptions "k8s.io/apiserver/pkg/server/options"
"k8s.io/client-go/dynamic"
"k8s.io/client-go/kubernetes"
"k8s.io/klog/v2"

"github.com/projectcalico/calico/apiserver/pkg/apiserver"
)
Expand Down Expand Up @@ -164,7 +164,7 @@ func (o *CalicoServerOptions) Config() (*apiserver.Config, error) {
// [1] https://kubernetes.io/blog/2024/04/24/validating-admission-policy-ga/
serverConfig.Authorization.Authorizer = authorizerfactory.NewAlwaysAllowAuthorizer()
// always warn when auth is disabled, since this should only be used for testing
klog.Infof("Authentication and authorization disabled for testing purposes")
logrus.Info("Authentication and authorization disabled for testing purposes")
}

if err := o.RecommendedOptions.Audit.ApplyTo(&serverConfig.Config); err != nil {
Expand Down
15 changes: 8 additions & 7 deletions apiserver/cmd/apiserver/server/run_server.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"os"
gpath "path"

"github.com/sirupsen/logrus"
"k8s.io/apiserver/pkg/admission/plugin/policy/validating"
genericapiserver "k8s.io/apiserver/pkg/server"
"k8s.io/apiserver/pkg/server/options"
Expand All @@ -52,7 +53,7 @@ func PrepareServer(opts *CalicoServerOptions) (*apiserver.ProjectCalicoServer, e
return nil, err
}

klog.V(4).Infoln("Completing API server configuration")
logrus.Debug("Completing API server configuration")
return config.Complete().New()
}

Expand All @@ -70,19 +71,19 @@ func RunServer(opts *CalicoServerOptions, server *apiserver.ProjectCalicoServer)
}()

go func() {
klog.Infoln("Starting watch extension")
logrus.Info("Starting watch extension")
changed, err := WatchExtensionAuth(ctx)
if err != nil {
klog.Errorln("Unable to watch the extension auth ConfigMap: ", err)
logrus.Error("Unable to watch the extension auth ConfigMap: ", err)
}
if changed {
klog.Infoln("Detected change in extension-apiserver-authentication ConfigMap, exiting so apiserver can be restarted")
logrus.Debug("Detected change in extension-apiserver-authentication ConfigMap, exiting so apiserver can be restarted")
cancel()
}
}()

go func() {
klog.Infoln("Running the API server")
logrus.Info("Running the API server")

// Start the Calico resource handler and shared informers and wait for sync before starting other components.
server.CalicoResourceLister.Start()
Expand All @@ -98,11 +99,11 @@ func RunServer(opts *CalicoServerOptions, server *apiserver.ProjectCalicoServer)
os.Exit(0)
return nil
}); err != nil {
klog.Errorln("failed to add post start hook swagger-printer:", err)
logrus.Error("failed to add post start hook swagger-printer:", err)
}
}
if err := server.GenericAPIServer.PrepareRun().Run(ctx.Done()); err != nil {
klog.Errorln("Error running API server: ", err)
logrus.Error("Error running API server: ", err)
}
}()

Expand Down
23 changes: 3 additions & 20 deletions apiserver/cmd/apiserver/server/server.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,36 +21,19 @@ package server
import (
"flag"
"io"
"os"

v3 "github.com/projectcalico/api/pkg/apis/projectcalico/v3"
"github.com/sirupsen/logrus"
"github.com/spf13/cobra"
genericoptions "k8s.io/apiserver/pkg/server/options"
"k8s.io/klog/v2"
"k8s.io/kubernetes/pkg/util/interrupt"

"github.com/projectcalico/calico/apiserver/pkg/apiserver"
"github.com/projectcalico/calico/libcalico-go/lib/logutils"
)

const defaultEtcdPathPrefix = ""

func logrusLevel() logrus.Level {
if env := os.Getenv("LOG_LEVEL"); env != "" {
return logutils.SafeParseLogLevel(env)
}

if klog.V(2).Enabled() {
return logrus.DebugLevel
}
if klog.V(1).Enabled() {
return logrus.InfoLevel
}
return logrus.ErrorLevel
}

// NewCommandStartCalicoServer provides a CLI handler for 'start master' command
// NewCommandStartMaster provides a CLI handler for 'start master' command
func NewCommandStartCalicoServer(out io.Writer) (*cobra.Command, *CalicoServerOptions, error) {
// o := NewCalicoServerOptions(out, errOut)

Expand All @@ -74,7 +57,7 @@ func NewCommandStartCalicoServer(out io.Writer) (*cobra.Command, *CalicoServerOp
opts.addFlags(flags)

cmd.Run = func(c *cobra.Command, args []string) {
logrus.SetLevel(logrusLevel())
configureLogging()

h := interrupt.New(nil, func() {
close(stopCh)
Expand All @@ -86,7 +69,7 @@ func NewCommandStartCalicoServer(out io.Writer) (*cobra.Command, *CalicoServerOp
}
return RunServer(opts, server)
}); err != nil {
klog.Fatalf("error running server (%s)", err)
logrus.Fatalf("error running server (%s)", err)
return
}
}
Expand Down
Loading

0 comments on commit 1e7b062

Please sign in to comment.