From 2887f9478e7c4562830119a1913a924eac12931b Mon Sep 17 00:00:00 2001 From: Menghan Li Date: Mon, 19 Jun 2017 13:57:04 -0700 Subject: [PATCH] Add Severity and VerboseLevel to grpclog. (#922) * Add Severity and VerboseLevel to grpclog. * keep old interface and add loggerv2 * export NewLoggerv2 --- grpclog/glogger/glogger.go | 57 +++++++++--- grpclog/grpclog.go | 127 ++++++++++++++++++++++++++ grpclog/logger.go | 66 ++++++++------ grpclog/loggerv2.go | 182 +++++++++++++++++++++++++++++++++++++ grpclog/loggerv2_test.go | 77 ++++++++++++++++ test/end2end_test.go | 9 +- 6 files changed, 467 insertions(+), 51 deletions(-) create mode 100644 grpclog/grpclog.go create mode 100644 grpclog/loggerv2.go create mode 100644 grpclog/loggerv2_test.go diff --git a/grpclog/glogger/glogger.go b/grpclog/glogger/glogger.go index 80ffff31f537..9fdce27d9728 100644 --- a/grpclog/glogger/glogger.go +++ b/grpclog/glogger/glogger.go @@ -17,41 +17,68 @@ */ // Package glogger defines glog-based logging for grpc. +// Importing this package will install glog as the logger used by grpclog. package glogger import ( - "fmt" - "github.com/golang/glog" "google.golang.org/grpc/grpclog" ) func init() { - grpclog.SetLogger(&glogger{}) + grpclog.SetLoggerV2(&glogger{}) } type glogger struct{} -func (g *glogger) Fatal(args ...interface{}) { - glog.FatalDepth(2, args...) +func (g *glogger) Info(args ...interface{}) { + glog.Info(args...) } -func (g *glogger) Fatalf(format string, args ...interface{}) { - glog.FatalDepth(2, fmt.Sprintf(format, args...)) +func (g *glogger) Infoln(args ...interface{}) { + glog.Infoln(args...) } -func (g *glogger) Fatalln(args ...interface{}) { - glog.FatalDepth(2, fmt.Sprintln(args...)) +func (g *glogger) Infof(format string, args ...interface{}) { + glog.Infof(format, args...) +} + +func (g *glogger) Warning(args ...interface{}) { + glog.Warning(args...) } -func (g *glogger) Print(args ...interface{}) { - glog.InfoDepth(2, args...) +func (g *glogger) Warningln(args ...interface{}) { + glog.Warningln(args...) } -func (g *glogger) Printf(format string, args ...interface{}) { - glog.InfoDepth(2, fmt.Sprintf(format, args...)) +func (g *glogger) Warningf(format string, args ...interface{}) { + glog.Warningf(format, args...) +} + +func (g *glogger) Error(args ...interface{}) { + glog.Error(args...) +} + +func (g *glogger) Errorln(args ...interface{}) { + glog.Errorln(args...) +} + +func (g *glogger) Errorf(format string, args ...interface{}) { + glog.Errorf(format, args...) +} + +func (g *glogger) Fatal(args ...interface{}) { + glog.Fatal(args...) +} + +func (g *glogger) Fatalln(args ...interface{}) { + glog.Fatalln(args...) +} + +func (g *glogger) Fatalf(format string, args ...interface{}) { + glog.Fatalf(format, args...) } -func (g *glogger) Println(args ...interface{}) { - glog.InfoDepth(2, fmt.Sprintln(args...)) +func (g *glogger) V(l int) bool { + return bool(glog.V(glog.Level(l))) } diff --git a/grpclog/grpclog.go b/grpclog/grpclog.go new file mode 100644 index 000000000000..23f28ec5c664 --- /dev/null +++ b/grpclog/grpclog.go @@ -0,0 +1,127 @@ +/* + * + * Copyright 2017, Google Inc. + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions are + * met: + * + * * Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * * Redistributions in binary form must reproduce the above + * copyright notice, this list of conditions and the following disclaimer + * in the documentation and/or other materials provided with the + * distribution. + * * Neither the name of Google Inc. nor the names of its + * contributors may be used to endorse or promote products derived from + * this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS + * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT + * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR + * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT + * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, + * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT + * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE + * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + */ + +package grpclog + +import "os" + +var logger = newLoggerV2() + +// V reports whether verbosity level l is at least the requested verbose level. +func V(l int) bool { + return logger.V(l) +} + +// Info logs to the INFO log. +func Info(args ...interface{}) { + logger.Info(args...) +} + +// Infof logs to the INFO log. Arguments are handled in the manner of fmt.Printf. +func Infof(format string, args ...interface{}) { + logger.Infof(format, args...) +} + +// Infoln logs to the INFO log. Arguments are handled in the manner of fmt.Println. +func Infoln(args ...interface{}) { + logger.Infoln(args...) +} + +// Warning logs to the WARNING log. +func Warning(args ...interface{}) { + logger.Warning(args...) +} + +// Warningf logs to the WARNING log. Arguments are handled in the manner of fmt.Printf. +func Warningf(format string, args ...interface{}) { + logger.Warningf(format, args...) +} + +// Warningln logs to the WARNING log. Arguments are handled in the manner of fmt.Println. +func Warningln(args ...interface{}) { + logger.Warningln(args...) +} + +// Error logs to the ERROR log. +func Error(args ...interface{}) { + logger.Error(args...) +} + +// Errorf logs to the ERROR log. Arguments are handled in the manner of fmt.Printf. +func Errorf(format string, args ...interface{}) { + logger.Errorf(format, args...) +} + +// Errorln logs to the ERROR log. Arguments are handled in the manner of fmt.Println. +func Errorln(args ...interface{}) { + logger.Errorln(args...) +} + +// Fatal logs to the FATAL log. Arguments are handled in the manner of fmt.Print. +// It calls os.Exit() with exit code 1. +func Fatal(args ...interface{}) { + logger.Fatal(args...) + os.Exit(1) +} + +// Fatalf logs to the FATAL log. Arguments are handled in the manner of fmt.Printf. +// It calles os.Exit() with exit code 1. +func Fatalf(format string, args ...interface{}) { + logger.Fatalf(format, args...) + os.Exit(1) +} + +// Fatalln logs to the FATAL log. Arguments are handled in the manner of fmt.Println. +// It calle os.Exit()) with exit code 1. +func Fatalln(args ...interface{}) { + logger.Fatalln(args...) + os.Exit(1) +} + +// Print prints to the logger. Arguments are handled in the manner of fmt.Print. +// Deprecated: use Info. +func Print(args ...interface{}) { + logger.Info(args...) +} + +// Printf prints to the logger. Arguments are handled in the manner of fmt.Printf. +// Deprecated: use Infof. +func Printf(format string, args ...interface{}) { + logger.Infof(format, args...) +} + +// Println prints to the logger. Arguments are handled in the manner of fmt.Println. +// Deprecated: use Infoln. +func Println(args ...interface{}) { + logger.Infoln(args...) +} diff --git a/grpclog/logger.go b/grpclog/logger.go index 72cb53243725..a87bb05ce825 100644 --- a/grpclog/logger.go +++ b/grpclog/logger.go @@ -19,17 +19,8 @@ // Package grpclog defines logging for grpc. package grpclog // import "google.golang.org/grpc/grpclog" -import ( - "log" - "os" -) - -// Use golang's standard logger by default. -// Access is not mutex-protected: do not modify except in init() -// functions. -var logger Logger = log.New(os.Stderr, "", log.LstdFlags) - // Logger mimics golang's standard Logger as an interface. +// Deprecated: use LoggerV2. type Logger interface { Fatal(args ...interface{}) Fatalf(format string, args ...interface{}) @@ -41,36 +32,53 @@ type Logger interface { // SetLogger sets the logger that is used in grpc. Call only from // init() functions. +// Deprecated: use SetLoggerV2. func SetLogger(l Logger) { - logger = l + logger = &loggerWrapper{Logger: l} +} + +// loggerWrapper wraps Logger into a LoggerV2. +type loggerWrapper struct { + Logger +} + +func (g *loggerWrapper) Info(args ...interface{}) { + g.Logger.Print(args...) +} + +func (g *loggerWrapper) Infoln(args ...interface{}) { + g.Logger.Println(args...) +} + +func (g *loggerWrapper) Infof(format string, args ...interface{}) { + g.Logger.Printf(format, args...) +} + +func (g *loggerWrapper) Warning(args ...interface{}) { + g.Logger.Print(args...) } -// Fatal is equivalent to Print() followed by a call to os.Exit() with a non-zero exit code. -func Fatal(args ...interface{}) { - logger.Fatal(args...) +func (g *loggerWrapper) Warningln(args ...interface{}) { + g.Logger.Println(args...) } -// Fatalf is equivalent to Printf() followed by a call to os.Exit() with a non-zero exit code. -func Fatalf(format string, args ...interface{}) { - logger.Fatalf(format, args...) +func (g *loggerWrapper) Warningf(format string, args ...interface{}) { + g.Logger.Printf(format, args...) } -// Fatalln is equivalent to Println() followed by a call to os.Exit()) with a non-zero exit code. -func Fatalln(args ...interface{}) { - logger.Fatalln(args...) +func (g *loggerWrapper) Error(args ...interface{}) { + g.Logger.Print(args...) } -// Print prints to the logger. Arguments are handled in the manner of fmt.Print. -func Print(args ...interface{}) { - logger.Print(args...) +func (g *loggerWrapper) Errorln(args ...interface{}) { + g.Logger.Println(args...) } -// Printf prints to the logger. Arguments are handled in the manner of fmt.Printf. -func Printf(format string, args ...interface{}) { - logger.Printf(format, args...) +func (g *loggerWrapper) Errorf(format string, args ...interface{}) { + g.Logger.Printf(format, args...) } -// Println prints to the logger. Arguments are handled in the manner of fmt.Println. -func Println(args ...interface{}) { - logger.Println(args...) +func (g *loggerWrapper) V(l int) bool { + // Returns true for all verbose level. + return true } diff --git a/grpclog/loggerv2.go b/grpclog/loggerv2.go new file mode 100644 index 000000000000..f0cbfec9a22c --- /dev/null +++ b/grpclog/loggerv2.go @@ -0,0 +1,182 @@ +/* + * + * Copyright 2017, Google Inc. + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions are + * met: + * + * * Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * * Redistributions in binary form must reproduce the above + * copyright notice, this list of conditions and the following disclaimer + * in the documentation and/or other materials provided with the + * distribution. + * * Neither the name of Google Inc. nor the names of its + * contributors may be used to endorse or promote products derived from + * this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS + * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT + * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR + * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT + * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, + * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT + * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE + * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + */ + +/* +Package grpclog defines logging for grpc. +*/ +package grpclog // import "google.golang.org/grpc/grpclog" + +import ( + "io" + "io/ioutil" + "log" + "os" +) + +// LoggerV2 does underlying logging work for grpclog. +type LoggerV2 interface { + // Info logs to INFO log. Arguments are handled in the manner of fmt.Print. + Info(args ...interface{}) + // Infoln logs to INFO log. Arguments are handled in the manner of fmt.Println. + Infoln(args ...interface{}) + // Infof logs to INFO log. Arguments are handled in the manner of fmt.Printf. + Infof(format string, args ...interface{}) + // Warning logs to WARNING log. Arguments are handled in the manner of fmt.Print. + Warning(args ...interface{}) + // Warningln logs to WARNING log. Arguments are handled in the manner of fmt.Println. + Warningln(args ...interface{}) + // Warningf logs to WARNING log. Arguments are handled in the manner of fmt.Printf. + Warningf(format string, args ...interface{}) + // Error logs to ERROR log. Arguments are handled in the manner of fmt.Print. + Error(args ...interface{}) + // Errorln logs to ERROR log. Arguments are handled in the manner of fmt.Println. + Errorln(args ...interface{}) + // Errorf logs to ERROR log. Arguments are handled in the manner of fmt.Printf. + Errorf(format string, args ...interface{}) + // Fatal logs to ERROR log. Arguments are handled in the manner of fmt.Print. + // This function should call os.Exit() with a non-zero exit code. + Fatal(args ...interface{}) + // Fatalln logs to ERROR log. Arguments are handled in the manner of fmt.Println. + // This function should call os.Exit() with a non-zero exit code. + Fatalln(args ...interface{}) + // Fatalf logs to ERROR log. Arguments are handled in the manner of fmt.Printf. + // This function should call os.Exit() with a non-zero exit code. + Fatalf(format string, args ...interface{}) + // V reports whether verbosity level l is at least the requested verbose level. + V(l int) bool +} + +// SetLoggerV2 sets logger that is used in grpc to a V2 logger. +// Not mutex-protected, should be called before any gRPC functions. +func SetLoggerV2(l LoggerV2) { + logger = l +} + +const ( + // infoLog indicates Info severity. + infoLog int = iota + // warningLog indicates Warning severity. + warningLog + // errorLog indicates Error severity. + errorLog + // fatalLog indicates Fatal severity. + fatalLog +) + +// severityName contains the string representation of each severity. +var severityName = []string{ + infoLog: "INFO", + warningLog: "WARNING", + errorLog: "ERROR", + fatalLog: "FATAL", +} + +// loggerT is the default logger used by grpclog. +type loggerT struct { + m []*log.Logger +} + +// NewLoggerV2 creates a loggerV2 with the provided writers. +// Fatal logs will be written to errorW, warningW, infoW, followed by exit(1). +// Error logs will be written to errorW, warningW and infoW. +// Warning logs will be written to warningW and infoW. +// Info logs will be written to infoW. +func NewLoggerV2(infoW, warningW, errorW io.Writer) LoggerV2 { + var m []*log.Logger + m = append(m, log.New(infoW, severityName[infoLog]+": ", log.LstdFlags)) + m = append(m, log.New(io.MultiWriter(infoW, warningW), severityName[warningLog]+": ", log.LstdFlags)) + ew := io.MultiWriter(infoW, warningW, errorW) // ew will be used for error and fatal. + m = append(m, log.New(ew, severityName[errorLog]+": ", log.LstdFlags)) + m = append(m, log.New(ew, severityName[fatalLog]+": ", log.LstdFlags)) + return &loggerT{m: m} +} + +// newLoggerV2 creates a loggerV2 to be used as default logger. +// All logs are written to stderr. +func newLoggerV2() LoggerV2 { + return NewLoggerV2(os.Stderr, ioutil.Discard, ioutil.Discard) +} + +func (g *loggerT) Info(args ...interface{}) { + g.m[infoLog].Print(args...) +} + +func (g *loggerT) Infoln(args ...interface{}) { + g.m[infoLog].Println(args...) +} + +func (g *loggerT) Infof(format string, args ...interface{}) { + g.m[infoLog].Printf(format, args...) +} + +func (g *loggerT) Warning(args ...interface{}) { + g.m[warningLog].Print(args...) +} + +func (g *loggerT) Warningln(args ...interface{}) { + g.m[warningLog].Println(args...) +} + +func (g *loggerT) Warningf(format string, args ...interface{}) { + g.m[warningLog].Printf(format, args...) +} + +func (g *loggerT) Error(args ...interface{}) { + g.m[errorLog].Print(args...) +} + +func (g *loggerT) Errorln(args ...interface{}) { + g.m[errorLog].Println(args...) +} + +func (g *loggerT) Errorf(format string, args ...interface{}) { + g.m[errorLog].Printf(format, args...) +} + +func (g *loggerT) Fatal(args ...interface{}) { + g.m[fatalLog].Fatal(args...) +} + +func (g *loggerT) Fatalln(args ...interface{}) { + g.m[fatalLog].Fatalln(args...) +} + +func (g *loggerT) Fatalf(format string, args ...interface{}) { + g.m[fatalLog].Fatalf(format, args...) +} + +func (g *loggerT) V(l int) bool { + // Returns true for all verbose level. + // TODO support verbose level in the default logger. + return true +} diff --git a/grpclog/loggerv2_test.go b/grpclog/loggerv2_test.go new file mode 100644 index 000000000000..61c0efe34046 --- /dev/null +++ b/grpclog/loggerv2_test.go @@ -0,0 +1,77 @@ +/* + * + * Copyright 2017, Google Inc. + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions are + * met: + * + * * Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * * Redistributions in binary form must reproduce the above + * copyright notice, this list of conditions and the following disclaimer + * in the documentation and/or other materials provided with the + * distribution. + * * Neither the name of Google Inc. nor the names of its + * contributors may be used to endorse or promote products derived from + * this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS + * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT + * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR + * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT + * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, + * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT + * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE + * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + */ + +package grpclog + +import ( + "bytes" + "fmt" + "regexp" + "testing" +) + +func TestLoggerV2Severity(t *testing.T) { + buffers := []*bytes.Buffer{new(bytes.Buffer), new(bytes.Buffer), new(bytes.Buffer)} + SetLoggerV2(NewLoggerV2(buffers[infoLog], buffers[warningLog], buffers[errorLog])) + + Info(severityName[infoLog]) + Warning(severityName[warningLog]) + Error(severityName[errorLog]) + + for i := 0; i < fatalLog; i++ { + buf := buffers[i] + // The content of info buffer should be something like: + // INFO: 2017/04/07 14:55:42 INFO + // WARNING: 2017/04/07 14:55:42 WARNING + // ERROR: 2017/04/07 14:55:42 ERROR + for j := i; j < fatalLog; j++ { + b, err := buf.ReadBytes('\n') + if err != nil { + t.Fatal(err) + } + if err := checkLogForSeverity(j, b); err != nil { + t.Fatal(err) + } + } + } +} + +// check if b is in the format of: +// WARNING: 2017/04/07 14:55:42 WARNING +func checkLogForSeverity(s int, b []byte) error { + expected := regexp.MustCompile(fmt.Sprintf(`^%s: [0-9]{4}/[0-9]{2}/[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2} %s\n$`, severityName[s], severityName[s])) + if m := expected.Match(b); !m { + return fmt.Errorf("got: %v, want string in format of: %v", string(b), severityName[s]+": 2016/10/05 17:09:26 "+severityName[s]) + } + return nil +} diff --git a/test/end2end_test.go b/test/end2end_test.go index e4febbca8b90..2ea848ab99d3 100644 --- a/test/end2end_test.go +++ b/test/end2end_test.go @@ -25,7 +25,6 @@ import ( "flag" "fmt" "io" - "log" "math" "net" "os" @@ -46,7 +45,7 @@ import ( "google.golang.org/grpc" "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" - "google.golang.org/grpc/grpclog" + _ "google.golang.org/grpc/grpclog/glogger" "google.golang.org/grpc/health" healthpb "google.golang.org/grpc/health/grpc_health_v1" "google.golang.org/grpc/internal" @@ -4240,12 +4239,12 @@ func interestingGoroutines() (gs []string) { strings.Contains(stack, "runtime.goexit") || strings.Contains(stack, "created by runtime.gc") || strings.Contains(stack, "created by runtime/trace.Start") || - strings.Contains(stack, "created by google3/base/go/log.init") || strings.Contains(stack, "interestingGoroutines") || strings.Contains(stack, "runtime.MHeap_Scavenger") || strings.Contains(stack, "signal.signal_recv") || strings.Contains(stack, "sigterm.handler") || strings.Contains(stack, "runtime_mcall") || + strings.Contains(stack, "(*loggingT).flushDaemon") || strings.Contains(stack, "goroutine in C code") { continue } @@ -4352,10 +4351,6 @@ func logOutputHasContents(v []byte, wakeup chan<- bool) bool { return false } -func init() { - grpclog.SetLogger(log.New(testLogOutput, "", log.LstdFlags)) -} - var verboseLogs = flag.Bool("verbose_logs", false, "show all grpclog output, without filtering") func noop() {}