Skip to content

Commit

Permalink
Logging module
Browse files Browse the repository at this point in the history
Introduce a filtered logging wrapper. logging conditions:
 * filter level of debug logs everything
 * all messages of warning or higher ignore log filters
 * info level messages honor verbosity
  • Loading branch information
stu-gott committed Jan 5, 2017
1 parent 505e6ee commit 0246528
Show file tree
Hide file tree
Showing 12 changed files with 445 additions and 44 deletions.
2 changes: 2 additions & 0 deletions cmd/virt-api/virt-api.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"golang.org/x/net/context"
"k8s.io/client-go/1.5/pkg/api/unversioned"
"kubevirt.io/kubevirt/pkg/api/v1"
"kubevirt.io/kubevirt/pkg/logging"
"kubevirt.io/kubevirt/pkg/virt-api/rest"
"log"
"net/http"
Expand All @@ -15,6 +16,7 @@ import (

func main() {

logging.InitializeLogging("virt-api")
swaggerui := flag.String("swagger-ui", "third_party/swagger-ui", "swagger-ui location")
host := flag.String("listen", "0.0.0.0", "Address and port where to listen on")
port := flag.Int("port", 8183, "Port to listen on")
Expand Down
18 changes: 9 additions & 9 deletions cmd/virt-controller/virt-controller.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,17 +3,15 @@ package main
import (
"flag"
"net/http"
"os"
"strconv"

"github.com/go-kit/kit/log"
"github.com/go-kit/kit/log/levels"
golog "log"

"github.com/emicklei/go-restful"
"github.com/facebookgo/inject"
"k8s.io/client-go/1.5/tools/cache"
"kubevirt.io/kubevirt/pkg/kubecli"
"kubevirt.io/kubevirt/pkg/logging"
"kubevirt.io/kubevirt/pkg/util"
"kubevirt.io/kubevirt/pkg/virt-controller/rest"
"kubevirt.io/kubevirt/pkg/virt-controller/services"
Expand All @@ -22,25 +20,26 @@ import (

func main() {

logging.InitializeLogging("virt-controller")
host := flag.String("listen", "0.0.0.0", "Address and port where to listen on")
port := flag.Int("port", 8182, "Port to listen on")
launcherImage := flag.String("launcher-image", "virt-launcher", "Shim container for containerized VMs")

logger := log.NewLogfmtLogger(os.Stderr)
logger := logging.DefaultLogger()
flag.Parse()

var g inject.Graph

vmService := services.NewVMService(logger)
templateService, err := services.NewTemplateService(logger, *launcherImage)
vmService := services.NewVMService()
templateService, err := services.NewTemplateService(*launcherImage)
if err != nil {
golog.Fatal(err)
}
vmHandler, err := watch.NewVMResourceEventHandler(logger)
vmHandler, err := watch.NewVMResourceEventHandler()
if err != nil {
golog.Fatal(err)
}
podHandler, err := watch.NewPodResourceEventHandler(logger)
podHandler, err := watch.NewPodResourceEventHandler()
if err != nil {
golog.Fatal(err)
}
Expand Down Expand Up @@ -92,7 +91,8 @@ func main() {
}
go podController.Run(stop)

httpLogger := levels.New(logger).With("component", "http")
httpLogger := logger.With("service", "http")

httpLogger.Info().Log("action", "listening", "interface", *host, "port", *port)
if err := http.ListenAndServe(*host+":"+strconv.Itoa(*port), nil); err != nil {
golog.Fatal(err)
Expand Down
6 changes: 5 additions & 1 deletion cmd/virt-handler/virt-handler.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import (
"k8s.io/client-go/1.5/tools/record"
"kubevirt.io/kubevirt/pkg/api/v1"
"kubevirt.io/kubevirt/pkg/kubecli"
"kubevirt.io/kubevirt/pkg/logging"
"kubevirt.io/kubevirt/pkg/virt-handler"
"kubevirt.io/kubevirt/pkg/virt-handler/libvirt"
virtcache "kubevirt.io/kubevirt/pkg/virt-handler/libvirt/cache"
Expand All @@ -22,6 +23,7 @@ import (

func main() {

logging.InitializeLogging("virt-handler")
libvirtapi.EventRegisterDefaultImpl()
libvirtUri := flag.String("libvirt-uri", "qemu:///system", "Libvirt connection string.")
libvirtUser := flag.String("user", "", "Libvirt user")
Expand All @@ -36,12 +38,14 @@ func main() {
}
*host = defaultHostName
}
fmt.Printf("Hostname: %s\n", *host)
log := logging.DefaultLogger()
log.Info().V(1).Log("hostname", *host)

go func() {
for {
if res := libvirtapi.EventRunDefaultImpl(); res < 0 {
// Report the error somehow or break the loop.
log.Warning().Log("msg", "No results from libvirt")
}
}
}()
Expand Down
2 changes: 2 additions & 0 deletions cmd/virt-launcher/virt-launcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (
"syscall"
"time"

"kubevirt.io/kubevirt/pkg/logging"
"strconv"
"strings"
)
Expand Down Expand Up @@ -120,6 +121,7 @@ func (mon *Monitor) RunForever(startTimeout time.Duration) {
func main() {
startTimeout := 0 * time.Second

logging.InitializeLogging("virt-launcher")
qemuTimeout := flag.Duration("qemu-timeout", startTimeout, "Amount of time to wait for qemu")
debugMode := flag.Bool("debug", false, "Enable debug messages")
flag.Parse()
Expand Down
6 changes: 3 additions & 3 deletions pkg/kubecli/kubecli.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@ package kubecli

import (
"flag"
"github.com/go-kit/kit/log/levels"
"k8s.io/client-go/1.5/kubernetes"
"k8s.io/client-go/1.5/pkg/api"
"k8s.io/client-go/1.5/pkg/fields"
Expand All @@ -14,6 +13,7 @@ import (
"k8s.io/client-go/1.5/tools/cache"
"k8s.io/client-go/1.5/tools/clientcmd"
"kubevirt.io/kubevirt/pkg/api/v1"
"kubevirt.io/kubevirt/pkg/logging"
"runtime/debug"
"time"
)
Expand Down Expand Up @@ -152,10 +152,10 @@ type ResourceEventHandler interface {
OnDelete(obj interface{}) error
}

func NewPanicCatcher(logger levels.Levels) func() {
func NewPanicCatcher(logger *logging.FilteredLogger) func() {
return func() {
if r := recover(); r != nil {
logger.Crit().Log("stacktrace", debug.Stack(), "msg", r)
logger.Critical().Log("stacktrace", debug.Stack(), "msg", r)
}
}
}
Expand Down
192 changes: 192 additions & 0 deletions pkg/logging/logging.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,192 @@
package logging

import (
"errors"
"flag"
"fmt"
"github.com/go-kit/kit/log"
"k8s.io/client-go/1.5/pkg/api/meta"
k8sruntime "k8s.io/client-go/1.5/pkg/runtime"
"os"
"path/filepath"
"runtime"
"strconv"
)

type logLevel int

const (
DEBUG logLevel = iota
INFO logLevel = iota
WARNING logLevel = iota
ERROR logLevel = iota
CRITICAL logLevel = iota
)

type LoggableObject interface {
meta.ObjectMetaAccessor
k8sruntime.Object
}

type FilteredLogger struct {
logContext *log.Context
filterLevel logLevel
currentLogLevel logLevel
verbosityLevel int
currentVerbosityLevel int
}

func InitializeLogging(comp string) {
flag.StringVar(&defaultComponent, "component", comp, "Default component for logs")
}

// Wrap a go-kit logger in a FilteredLogger. Not cached
func MakeLogger(logger log.Logger) *FilteredLogger {
defaultLogLevel := INFO

if verbosityFlag := flag.Lookup("v"); verbosityFlag != nil {
defaultVerbosity, _ = strconv.Atoi(verbosityFlag.Value.String())
} else {
defaultVerbosity = 0
}
return &FilteredLogger{
logContext: log.NewContext(logger).With("component", defaultComponent),
filterLevel: defaultLogLevel,
currentLogLevel: defaultLogLevel,
verbosityLevel: defaultVerbosity,
currentVerbosityLevel: defaultVerbosity,
}
}

type NullLogger struct{}

func (n NullLogger) Log(params ...interface{}) error { return nil }

var loggers = make(map[string]*FilteredLogger)
var defaultComponent = ""
var defaultVerbosity = 0

func Logger(component string) *FilteredLogger {
if _, ok := loggers[component]; !ok {
logger := log.NewLogfmtLogger(os.Stderr)
log := MakeLogger(logger).With("component", component)
loggers[component] = log
}
return loggers[component]
}

func DefaultLogger() *FilteredLogger {
return Logger(defaultComponent)
}

func (l *FilteredLogger) SetLogger(logger log.Logger) *FilteredLogger {
l.logContext = log.NewContext(logger)
return l
}

type LogError struct {
message string
}

func (e LogError) Error() string {
return e.message
}

func (l FilteredLogger) Log(params ...interface{}) error {
// messages should be logged if any of these conditions are met:
// The log filtering level is debug
// The log filtering level is info and verbosity checks match
// The log message priority is warning or higher
force := (l.filterLevel == DEBUG) || (l.currentLogLevel >= WARNING)

if force || (l.filterLevel == INFO &&
(l.currentLogLevel == l.filterLevel) &&
(l.currentVerbosityLevel <= l.verbosityLevel)) {
logParams := make([]interface{}, 0)

if l.currentVerbosityLevel > 1 {
_, fileName, lineNumber, _ := runtime.Caller(1)
logParams = append(logParams, "filename", filepath.Base(fileName))
logParams = append(logParams, "line", lineNumber)
}
logParams = append(logParams, params...)
return l.logContext.Log(logParams...)
}
return nil
}

func (l FilteredLogger) Object(obj LoggableObject) *FilteredLogger {

name := obj.GetObjectMeta().GetName()
uid := obj.GetObjectMeta().GetUID()
kind := obj.GetObjectKind()

logParams := make([]interface{}, 0)
logParams = append(logParams, "name", name)
logParams = append(logParams, "kind", kind)
logParams = append(logParams, "uid", uid)

l.logContext.With(logParams)
return &l
}

func (l *FilteredLogger) With(obj ...interface{}) *FilteredLogger {
l.logContext.With(obj...)
return l
}

func (l *FilteredLogger) WithPrefix(obj ...interface{}) *FilteredLogger {
l.logContext.WithPrefix(obj...)
return l
}

func (l *FilteredLogger) SetLogLevel(filterLevel logLevel) error {
if (filterLevel >= DEBUG) && (filterLevel <= CRITICAL) {
l.filterLevel = filterLevel
return nil
}
return errors.New(fmt.Sprintf("Log level %d does not exist", filterLevel))
}

func (l *FilteredLogger) SetVerbosityLevel(level int) error {
if level >= 0 {
l.verbosityLevel = level
} else {
return errors.New("Verbosity setting must not be negative")
}
return nil
}

// It would be consistent to return an error from this function, but
// a multi-value function would break the primary use case: log.V(2).Info()....
func (l FilteredLogger) V(level int) *FilteredLogger {
if level >= 0 {
l.currentVerbosityLevel = level
}
return &l
}

func (l FilteredLogger) Debug() *FilteredLogger {
l.currentLogLevel = DEBUG
return &l
}

func (l FilteredLogger) Info() *FilteredLogger {
l.currentLogLevel = INFO
return &l
}

func (l FilteredLogger) Warning() *FilteredLogger {
l.currentLogLevel = WARNING
return &l
}

func (l FilteredLogger) Error() *FilteredLogger {
l.currentLogLevel = ERROR
return &l
}

func (l FilteredLogger) Critical() *FilteredLogger {
l.currentLogLevel = CRITICAL
return &l
}
Loading

0 comments on commit 0246528

Please sign in to comment.