diff --git a/bench_test.go b/bench_test.go index ec12db14..5e99094e 100644 --- a/bench_test.go +++ b/bench_test.go @@ -273,6 +273,23 @@ func BenchmarkSelectWithoutLogging(b *testing.B) { benchmarkSelectWithLog(b, conn) } +func BenchmarkSelectWithLoggingTraceWithLog15(b *testing.B) { + connConfig := *defaultConnConfig + + logger := log.New() + lvl, err := log.LvlFromString("debug") + if err != nil { + b.Fatal(err) + } + logger.SetHandler(log.LvlFilterHandler(lvl, log.DiscardHandler())) + connConfig.Logger = logger + connConfig.LogLevel = pgx.LogLevelTrace + conn := mustConnect(b, connConfig) + defer closeConn(b, conn) + + benchmarkSelectWithLog(b, conn) +} + func BenchmarkSelectWithLoggingDebugWithLog15(b *testing.B) { connConfig := *defaultConnConfig @@ -283,6 +300,7 @@ func BenchmarkSelectWithLoggingDebugWithLog15(b *testing.B) { } logger.SetHandler(log.LvlFilterHandler(lvl, log.DiscardHandler())) connConfig.Logger = logger + connConfig.LogLevel = pgx.LogLevelDebug conn := mustConnect(b, connConfig) defer closeConn(b, conn) @@ -299,6 +317,7 @@ func BenchmarkSelectWithLoggingInfoWithLog15(b *testing.B) { } logger.SetHandler(log.LvlFilterHandler(lvl, log.DiscardHandler())) connConfig.Logger = logger + connConfig.LogLevel = pgx.LogLevelInfo conn := mustConnect(b, connConfig) defer closeConn(b, conn) @@ -315,6 +334,7 @@ func BenchmarkSelectWithLoggingErrorWithLog15(b *testing.B) { } logger.SetHandler(log.LvlFilterHandler(lvl, log.DiscardHandler())) connConfig.Logger = logger + connConfig.LogLevel = pgx.LogLevelError conn := mustConnect(b, connConfig) defer closeConn(b, conn) diff --git a/conn.go b/conn.go index acf24a8a..24aecc0b 100644 --- a/conn.go +++ b/conn.go @@ -124,6 +124,8 @@ func Connect(config ConnConfig) (c *Conn, err error) { if c.logger == nil { c.logLevel = LogLevelNone } + c.mr.logger = c.logger + c.mr.logLevel = c.logLevel if c.config.User == "" { user, err := user.Current() @@ -956,7 +958,7 @@ func (c *Conn) rxMsg() (t byte, r *msgReader, err error) { c.lastActivityTime = time.Now() if c.logLevel >= LogLevelTrace { - c.logger.Debug("rxMsg", "Type", string(t), "Size", c.mr.msgBytesRemaining) + c.logger.Debug("rxMsg", "type", string(t), "msgBytesRemaining", c.mr.msgBytesRemaining) } return t, &c.mr, err diff --git a/doc.go b/doc.go index edbfd79d..d39d1c2a 100644 --- a/doc.go +++ b/doc.go @@ -192,7 +192,8 @@ Logging pgx defines a simple logger interface. Connections optionally accept a logger that satisfies this interface. The log15 package -(http://gopkg.in/inconshreveable/log15.v2) satisfies this interface -and it is simple to define adapters for other loggers. +(http://gopkg.in/inconshreveable/log15.v2) satisfies this interface and it is +simple to define adapters for other loggers. Set LogLevel to control logging +verbosity. */ package pgx diff --git a/msg_reader.go b/msg_reader.go index 0b72c30c..9098c20a 100644 --- a/msg_reader.go +++ b/msg_reader.go @@ -14,6 +14,8 @@ type msgReader struct { buf [128]byte msgBytesRemaining int32 err error + logger Logger + logLevel int } // Err returns any error that the msgReader has experienced @@ -23,6 +25,9 @@ func (r *msgReader) Err() error { // fatal tells r that a Fatal error has occurred func (r *msgReader) fatal(err error) { + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.fatal", "error", err, "msgBytesRemaining", r.msgBytesRemaining) + } r.err = err } @@ -33,6 +38,10 @@ func (r *msgReader) rxMsg() (t byte, err error) { } if r.msgBytesRemaining > 0 { + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.rxMsg discarding unread previous message", "msgBytesRemaining", r.msgBytesRemaining) + } + io.CopyN(ioutil.Discard, r.reader, int64(r.msgBytesRemaining)) } @@ -59,6 +68,10 @@ func (r *msgReader) readByte() byte { return 0 } + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readByte", "value", b, "byteAsString", string(b), "msgBytesRemaining", r.msgBytesRemaining) + } + return b } @@ -80,7 +93,13 @@ func (r *msgReader) readInt16() int16 { return 0 } - return int16(binary.BigEndian.Uint16(b)) + n := int16(binary.BigEndian.Uint16(b)) + + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readInt16", "value", n, "msgBytesRemaining", r.msgBytesRemaining) + } + + return n } func (r *msgReader) readInt32() int32 { @@ -101,7 +120,13 @@ func (r *msgReader) readInt32() int32 { return 0 } - return int32(binary.BigEndian.Uint32(b)) + n := int32(binary.BigEndian.Uint32(b)) + + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readInt32", "value", n, "msgBytesRemaining", r.msgBytesRemaining) + } + + return n } func (r *msgReader) readInt64() int64 { @@ -122,7 +147,13 @@ func (r *msgReader) readInt64() int64 { return 0 } - return int64(binary.BigEndian.Uint64(b)) + n := int64(binary.BigEndian.Uint64(b)) + + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readInt64", "value", n, "msgBytesRemaining", r.msgBytesRemaining) + } + + return n } func (r *msgReader) readOid() Oid { @@ -147,7 +178,13 @@ func (r *msgReader) readCString() string { return "" } - return string(b[0 : len(b)-1]) + s := string(b[0 : len(b)-1]) + + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readCString", "value", s, "msgBytesRemaining", r.msgBytesRemaining) + } + + return s } // readString reads count bytes and returns as string @@ -175,7 +212,13 @@ func (r *msgReader) readString(count int32) string { return "" } - return string(b) + s := string(b) + + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readString", "value", s, "msgBytesRemaining", r.msgBytesRemaining) + } + + return s } // readBytes reads count bytes and returns as []byte @@ -198,5 +241,9 @@ func (r *msgReader) readBytes(count int32) []byte { return nil } + if r.logLevel >= LogLevelTrace { + r.logger.Debug("msgReader.readBytes", "value", b, "msgBytesRemaining", r.msgBytesRemaining) + } + return b }