address PR feedback

Author: joao-r-reis

cluster.go

@@ -261,9 +261,7 @@ type ClusterConfig struct {
 
 	// StructuredLogger for this ClusterConfig.
 	//
-	// You can change the log level of the default logger by creating a new logger using gocql.NewLogger and providing it here.
-	//
-	//There are 3 built in implementations of StructuredLogger:
+	// There are 3 built in implementations of StructuredLogger:
 	//  - std library "log" package: gocql.NewLogger
 	//  - zerolog: gocqlzerolog.NewZerologLogger
 	//  - zap: gocqlzap.NewZapLogger

conn_test.go

@@ -349,23 +349,20 @@ func TestCancel(t *testing.T) {
 
 type testQueryObserver struct {
 	metrics map[string]*hostMetrics
-	verbose bool
 	logger  StructuredLogger
 }
 
 func (o *testQueryObserver) ObserveQuery(ctx context.Context, q ObservedQuery) {
 	host := q.Host.ConnectAddress().String()
 	o.metrics[host] = q.Metrics
-	if o.verbose {
-		o.logger.Debug("Observed query.",
-			newLogFieldString("stmt", q.Statement),
-			newLogFieldInt("rows", q.Rows),
-			newLogFieldString("duration", q.End.Sub(q.Start).String()),
-			newLogFieldString("host", host),
-			newLogFieldInt("attempts", q.Metrics.Attempts),
-			newLogFieldString("latency", strconv.FormatInt(q.Metrics.TotalLatency, 10)),
-			newLogFieldError("err", q.Err))
-	}
+	o.logger.Debug("Observed query.",
+		newLogFieldString("stmt", q.Statement),
+		newLogFieldInt("rows", q.Rows),
+		newLogFieldString("duration", q.End.Sub(q.Start).String()),
+		newLogFieldString("host", host),
+		newLogFieldInt("attempts", q.Metrics.Attempts),
+		newLogFieldString("latency", strconv.FormatInt(q.Metrics.TotalLatency, 10)),
+		newLogFieldError("err", q.Err))
 }
 
 func (o *testQueryObserver) GetMetrics(host *HostInfo) *hostMetrics {
@@ -418,7 +415,7 @@ func TestQueryRetry(t *testing.T) {
 }
 
 func TestQueryMultinodeWithMetrics(t *testing.T) {
-	log := newTestLogger(LogLevelDebug)
+	log := newTestLogger(LogLevelNone)
 	defer func() {
 		os.Stdout.WriteString(log.String())
 	}()
@@ -446,7 +443,7 @@ func TestQueryMultinodeWithMetrics(t *testing.T) {
 
 	// 1 retry per host
 	rt := &SimpleRetryPolicy{NumRetries: 3}
-	observer := &testQueryObserver{metrics: make(map[string]*hostMetrics), verbose: false, logger: log}
+	observer := &testQueryObserver{metrics: make(map[string]*hostMetrics), logger: log}
 	qry := db.Query("kill").RetryPolicy(rt).Observer(observer).Idempotent(true)
 	iter := qry.Iter()
 	err = iter.Close()
@@ -731,7 +728,7 @@ func TestStream0(t *testing.T) {
 		session: &Session{
 			types: GlobalTypes,
 		},
-		logger:  NewLogger(LogLevelNone),
+		logger: NewLogger(LogLevelNone),
 	}
 
 	err := conn.recv(context.Background(), false)

control.go

@@ -264,7 +264,7 @@ func (c *controlConn) discoverProtocol(hosts []*HostInfo) (int, error) {
 	return 0, err
 }
 
-func (c *controlConn) connect(hosts []*HostInfo) error {
+func (c *controlConn) connect(hosts []*HostInfo, sessionInit bool) error {
 	if len(hosts) == 0 {
 		return errors.New("control: no endpoints specified")
 	}
@@ -288,7 +288,7 @@ func (c *controlConn) connect(hosts []*HostInfo) error {
 				newLogFieldError("err", err))
 			continue
 		}
-		err = c.setupConn(conn)
+		err = c.setupConn(conn, sessionInit)
 		if err == nil {
 			break
 		}
@@ -317,7 +317,7 @@ type connHost struct {
 	host *HostInfo
 }
 
-func (c *controlConn) setupConn(conn *Conn) error {
+func (c *controlConn) setupConn(conn *Conn, sessionInit bool) error {
 	// we need up-to-date host info for the filterHost call below
 	iter := conn.querySystemLocal(context.TODO())
 	host, err := c.session.hostInfoFromIter(iter, conn.host.connectAddress, conn.r.RemoteAddr().(*net.TCPAddr).Port)
@@ -333,7 +333,13 @@ func (c *controlConn) setupConn(conn *Conn) error {
 	}
 
 	if !exists {
-		c.session.logger.Info("Adding host.",
+		logLevel := LogLevelInfo
+		msg := "Added control host."
+		if sessionInit {
+			logLevel = LogLevelDebug
+			msg = "Added control host (session initialization)."
+		}
+		logHelper(c.session.logger, logLevel, msg,
 			newLogFieldIp("host_addr", host.ConnectAddress()), newLogFieldString("host_id", host.HostID()))
 	}
 
@@ -424,7 +430,7 @@ func (c *controlConn) reconnect() {
 
 func (c *controlConn) attemptReconnect() (*Conn, error) {
 
-	c.session.logger.Info("Reconnecting the control connection.")
+	c.session.logger.Debug("Reconnecting the control connection.")
 
 	hosts := c.session.ring.allHosts()
 	hosts = shuffleHosts(hosts)
@@ -472,7 +478,7 @@ func (c *controlConn) attemptReconnectToAnyOfHosts(hosts []*HostInfo) (*Conn, er
 				newLogFieldError("err", err))
 			continue
 		}
-		err = c.setupConn(conn)
+		err = c.setupConn(conn, false)
 		if err == nil {
 			break
 		}
@@ -500,7 +506,7 @@ func (c *controlConn) HandleError(conn *Conn, err error, closed bool) {
 		return
 	}
 
-	c.session.logger.Info("Control connection error.",
+	c.session.logger.Warning("Control connection error.",
 		newLogFieldIp("host_addr", conn.host.ConnectAddress()),
 		newLogFieldString("host_id", conn.host.HostID()),
 		newLogFieldError("err", err))

events.go

@@ -180,7 +180,7 @@ func (s *Session) handleNodeEvent(frames []frame) {
 	for _, frame := range frames {
 		switch f := frame.(type) {
 		case *topologyChangeEventFrame:
-			s.logger.Warning("Received topology change event.",
+			s.logger.Info("Received topology change event.",
 				newLogFieldString("frame", strings.Join([]string{f.change, "->", f.host.String(), ":", strconv.Itoa(f.port)}, "")))
 			topologyEventReceived = true
 		case *statusChangeEventFrame:

logger.go

@@ -37,6 +37,21 @@ import (
 // Deprecated: use StructuredLogger instead
 type StdLogger interface{}
 
+func logHelper(logger StructuredLogger, level LogLevel, msg string, fields... LogField) {
+	switch level {
+	case LogLevelDebug:
+		logger.Debug(msg, fields...)
+	case LogLevelInfo:
+		logger.Info(msg, fields...)
+	case LogLevelWarn:
+		logger.Warning(msg, fields...)
+	case LogLevelError:
+		logger.Error(msg, fields...)
+	default:
+		logger.Error("Unknown log level", newLogFieldInt("level", int(level)), newLogFieldString("msg", msg))
+	}
+}
+
 type nopLogger struct{}
 
 func (n nopLogger) Error(_ string, _ ...LogField) {}
@@ -101,7 +116,21 @@ type defaultLogger struct {
 	logLevel LogLevel
 }
 
-// NewLogger creates an StructuredLogger that uses the standard library "log" package.
+// NewLogger creates a StructuredLogger that uses the standard library log package.
+//
+// This logger will write log messages in the following format:
+//
+//	<LOG_LEVEL> gocql: <message> <fields[0].Name>=<fields[0].Value> <fields[1].Name>=<fields[1].Value>
+//
+// LOG_LEVEL is always a 3 letter string:
+//   - DEBUG -> DBG
+//   - INFO -> INF
+//   - WARNING -> WRN
+//   - ERROR -> ERR
+//
+// Example:
+//
+//	INF gocql: Adding host (session initialization). host_addr=127.0.0.1 host_id=a21dd06e-9e7e-4528-8ad7-039604e25e73
 func NewLogger(logLevel LogLevel) StructuredLogger {
 	return &defaultLogger{logLevel: logLevel}
 }
@@ -197,7 +226,9 @@ func newLogField(name string, value LogFieldValue) LogField {
 
 func newLogFieldIp(name string, value net.IP) LogField {
 	var str string
-	if value != nil {
+	if value == nil {
+		str = "<nil>"
+	} else {
 		str = value.String()
 	}
 	return newLogField(name, logFieldValueString(str))
@@ -246,7 +277,7 @@ type LogFieldValue struct {
 	any interface{}
 }
 
-// LogFieldValueType is the type of a [LogFieldValue].
+// LogFieldValueType is the type of a LogFieldValue.
 type LogFieldValueType int
 
 // It's important that LogFieldTypeAny is 0 so that a zero Value represents nil.
@@ -270,7 +301,7 @@ func (v LogFieldValue) LogFieldValueType() LogFieldValueType {
 }
 
 func logFieldValueString(value string) LogFieldValue {
-	return LogFieldValue{num: uint64(len(value)), any: value}
+	return LogFieldValue{any: value}
 }
 
 func logFieldValueInt(v int) LogFieldValue {
@@ -308,9 +339,11 @@ func (v LogFieldValue) Any() interface{} {
 	}
 }
 
-// String returns Value's value as a string, formatted like [fmt.Sprint]. Unlike
-// the methods Int64, Float64, and so on, which panic if v is of the
-// wrong kind, String never panics.
+// String returns LogFieldValue's value as a string, formatted like fmt.Sprint.
+//
+// Unlike the methods Int64 and Bool which panic if v is of the
+// wrong LogFieldValueType, String never panics
+// (i.e. it can be called for any LogFieldValueType, not just LogFieldTypeString)
 func (v LogFieldValue) String() string {
 	return v.stringValue()
 }

session.go

@@ -237,7 +237,7 @@ func (s *Session) init() error {
 			s.logger.Info("Discovered protocol version.", newLogFieldInt("protocol_version", proto))
 		}
 
-		if err := s.control.connect(hosts); err != nil {
+		if err := s.control.connect(hosts, true); err != nil {
 			return err
 		}
 
@@ -410,7 +410,7 @@ func (s *Session) reconnectDownedHosts(intv time.Duration) {
 				if h.IsUp() {
 					continue
 				}
-				s.logger.Info("Reconnecting to downed host.",
+				s.logger.Debug("Reconnecting to downed host.",
 					newLogFieldIp("host_addr", h.ConnectAddress()),
 					newLogFieldInt("host_port", h.Port()),
 					newLogFieldString("host_id", h.HostID()))