From d06957b8d82518faadb04776a3eec425c6a369b1 Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Sun, 27 May 2018 17:07:36 +0800 Subject: [PATCH 1/2] implement a prefix logger --- internal/utils/log.go | 24 +++++++++++++++++++--- internal/utils/log_test.go | 41 +++++++++++++++++++++++++++----------- 2 files changed, 50 insertions(+), 15 deletions(-) diff --git a/internal/utils/log.go b/internal/utils/log.go index 62a3d075e..e27f01b4a 100644 --- a/internal/utils/log.go +++ b/internal/utils/log.go @@ -28,6 +28,7 @@ const logEnv = "QUIC_GO_LOG_LEVEL" type Logger interface { SetLogLevel(LogLevel) SetLogTimeFormat(format string) + WithPrefix(prefix string) Logger Debug() bool Errorf(format string, args ...interface{}) @@ -39,6 +40,8 @@ type Logger interface { var DefaultLogger Logger type defaultLogger struct { + prefix string + logLevel LogLevel timeFormat string } @@ -79,10 +82,25 @@ func (l *defaultLogger) Errorf(format string, args ...interface{}) { } func (l *defaultLogger) logMessage(format string, args ...interface{}) { + var pre string + if len(l.timeFormat) > 0 { - log.Printf(time.Now().Format(l.timeFormat)+" "+format, args...) - } else { - log.Printf(format, args...) + pre = time.Now().Format(l.timeFormat) + " " + } + if len(l.prefix) > 0 { + pre += l.prefix + " " + } + log.Printf(pre+format, args...) +} + +func (l *defaultLogger) WithPrefix(prefix string) Logger { + if len(l.prefix) > 0 { + prefix = l.prefix + " " + prefix + } + return &defaultLogger{ + logLevel: l.logLevel, + timeFormat: l.timeFormat, + prefix: prefix, } } diff --git a/internal/utils/log_test.go b/internal/utils/log_test.go index dcd904aff..0cda45837 100644 --- a/internal/utils/log_test.go +++ b/internal/utils/log_test.go @@ -35,7 +35,7 @@ var _ = Describe("Log", func() { DefaultLogger.Debugf("debug") DefaultLogger.Infof("info") DefaultLogger.Errorf("err") - Expect(b.Bytes()).To(Equal([]byte(""))) + Expect(b.String()).To(BeEmpty()) }) It("log level err", func() { @@ -43,9 +43,9 @@ var _ = Describe("Log", func() { DefaultLogger.Debugf("debug") DefaultLogger.Infof("info") DefaultLogger.Errorf("err") - Expect(b.Bytes()).To(ContainSubstring("err\n")) - Expect(b.Bytes()).ToNot(ContainSubstring("info")) - Expect(b.Bytes()).ToNot(ContainSubstring("debug")) + Expect(b.String()).To(ContainSubstring("err\n")) + Expect(b.String()).ToNot(ContainSubstring("info")) + Expect(b.String()).ToNot(ContainSubstring("debug")) }) It("log level info", func() { @@ -53,9 +53,9 @@ var _ = Describe("Log", func() { DefaultLogger.Debugf("debug") DefaultLogger.Infof("info") DefaultLogger.Errorf("err") - Expect(b.Bytes()).To(ContainSubstring("err\n")) - Expect(b.Bytes()).To(ContainSubstring("info\n")) - Expect(b.Bytes()).ToNot(ContainSubstring("debug")) + Expect(b.String()).To(ContainSubstring("err\n")) + Expect(b.String()).To(ContainSubstring("info\n")) + Expect(b.String()).ToNot(ContainSubstring("debug")) }) It("log level debug", func() { @@ -63,16 +63,16 @@ var _ = Describe("Log", func() { DefaultLogger.Debugf("debug") DefaultLogger.Infof("info") DefaultLogger.Errorf("err") - Expect(b.Bytes()).To(ContainSubstring("err\n")) - Expect(b.Bytes()).To(ContainSubstring("info\n")) - Expect(b.Bytes()).To(ContainSubstring("debug\n")) + Expect(b.String()).To(ContainSubstring("err\n")) + Expect(b.String()).To(ContainSubstring("info\n")) + Expect(b.String()).To(ContainSubstring("debug\n")) }) It("doesn't add a timestamp if the time format is empty", func() { DefaultLogger.SetLogLevel(LogLevelDebug) DefaultLogger.SetLogTimeFormat("") DefaultLogger.Debugf("debug") - Expect(b.Bytes()).To(Equal([]byte("debug\n"))) + Expect(b.String()).To(Equal("debug\n")) }) It("adds a timestamp", func() { @@ -80,7 +80,7 @@ var _ = Describe("Log", func() { DefaultLogger.SetLogTimeFormat(format) DefaultLogger.SetLogLevel(LogLevelInfo) DefaultLogger.Infof("info") - t, err := time.Parse(format, string(b.Bytes()[:b.Len()-6])) + t, err := time.Parse(format, string(b.String()[:b.Len()-6])) Expect(err).ToNot(HaveOccurred()) Expect(t).To(BeTemporally("~", time.Now(), 25*time.Hour)) }) @@ -91,6 +91,23 @@ var _ = Describe("Log", func() { Expect(DefaultLogger.Debug()).To(BeTrue()) }) + It("adds a prefix", func() { + DefaultLogger.SetLogLevel(LogLevelDebug) + prefixLogger := DefaultLogger.WithPrefix("prefix") + prefixLogger.Debugf("debug") + Expect(b.String()).To(ContainSubstring("prefix")) + Expect(b.String()).To(ContainSubstring("debug")) + }) + + It("adds multiple prefixes", func() { + DefaultLogger.SetLogLevel(LogLevelDebug) + prefixLogger := DefaultLogger.WithPrefix("prefix1") + prefixPrefixLogger := prefixLogger.WithPrefix("prefix2") + prefixPrefixLogger.Debugf("debug") + Expect(b.String()).To(ContainSubstring("prefix")) + Expect(b.String()).To(ContainSubstring("debug")) + }) + Context("reading from env", func() { BeforeEach(func() { Expect(DefaultLogger.(*defaultLogger).logLevel).To(Equal(LogLevelNothing)) From 6b82e46e0cb0ccd54c8a15e56d1d2c677eb825e3 Mon Sep 17 00:00:00 2001 From: Marten Seemann Date: Sat, 31 Mar 2018 14:25:05 +0700 Subject: [PATCH 2/2] use the prefix logger for client, server and proxy --- client.go | 2 +- h2quic/client.go | 2 +- h2quic/server.go | 2 +- integrationtests/tools/proxy/proxy.go | 2 +- server.go | 2 +- 5 files changed, 5 insertions(+), 5 deletions(-) diff --git a/client.go b/client.go index dab09ea93..4bd98f625 100644 --- a/client.go +++ b/client.go @@ -112,7 +112,7 @@ func Dial( tlsConf: tlsConf, config: clientConfig, version: version, - logger: utils.DefaultLogger, + logger: utils.DefaultLogger.WithPrefix("client"), } c.logger.Infof("Starting new connection to %s (%s -> %s), source connection ID %s, destination connection ID %s, version %s", hostname, c.conn.LocalAddr(), c.conn.RemoteAddr(), c.srcConnID, c.destConnID, c.version) diff --git a/h2quic/client.go b/h2quic/client.go index 409808827..af4ad11a0 100644 --- a/h2quic/client.go +++ b/h2quic/client.go @@ -77,7 +77,7 @@ func newClient( opts: opts, headerErrored: make(chan struct{}), dialer: dialer, - logger: utils.DefaultLogger, + logger: utils.DefaultLogger.WithPrefix("client"), } } diff --git a/h2quic/server.go b/h2quic/server.go index a2412bd16..857211d2e 100644 --- a/h2quic/server.go +++ b/h2quic/server.go @@ -90,7 +90,7 @@ func (s *Server) serveImpl(tlsConfig *tls.Config, conn net.PacketConn) error { if s.Server == nil { return errors.New("use of h2quic.Server without http.Server") } - s.logger = utils.DefaultLogger + s.logger = utils.DefaultLogger.WithPrefix("server") s.listenerMutex.Lock() if s.closed { s.listenerMutex.Unlock() diff --git a/integrationtests/tools/proxy/proxy.go b/integrationtests/tools/proxy/proxy.go index d12a3baea..d0bd97109 100644 --- a/integrationtests/tools/proxy/proxy.go +++ b/integrationtests/tools/proxy/proxy.go @@ -134,7 +134,7 @@ func NewQuicProxy(local string, version protocol.VersionNumber, opts *Opts) (*Qu dropPacket: packetDropper, delayPacket: packetDelayer, version: version, - logger: utils.DefaultLogger, + logger: utils.DefaultLogger.WithPrefix("proxy"), } p.logger.Debugf("Starting UDP Proxy %s <-> %s", conn.LocalAddr(), raddr) diff --git a/server.go b/server.go index 31b7911c5..02a9d0777 100644 --- a/server.go +++ b/server.go @@ -110,7 +110,7 @@ func Listen(conn net.PacketConn, tlsConf *tls.Config, config *Config) (Listener, sessionQueue: make(chan Session, 5), errorChan: make(chan struct{}), supportsTLS: supportsTLS, - logger: utils.DefaultLogger, + logger: utils.DefaultLogger.WithPrefix("server"), } if supportsTLS { if err := s.setupTLS(); err != nil {