GODRIVER-3173 Fix bugs in events and logs

Author: prestonvasquez

internal/logger/component.go

@@ -28,9 +28,9 @@ const (
 	ConnectionCheckoutFailed         = "Connection checkout failed"
 	ConnectionCheckedOut             = "Connection checked out"
 	ConnectionCheckedIn              = "Connection checked in"
-	ConnectionPendingReadStarted     = "Pending read started"
-	ConnectionPendingReadSucceeded   = "Pending read succeeded"
-	ConnectionPendingReadFailed      = "Pending read failed"
+	ConnectionPendingReadStarted     = "Pending response started"
+	ConnectionPendingReadSucceeded   = "Pending response succeeded"
+	ConnectionPendingReadFailed      = "Pending response failed"
 	ServerSelectionFailed            = "Server selection failed"
 	ServerSelectionStarted           = "Server selection started"
 	ServerSelectionSucceeded         = "Server selection succeeded"

x/mongo/driver/topology/cmap_prose_test.go

@@ -361,7 +361,7 @@ func TestCMAPProse(t *testing.T) {
 		assert.Equal(t, addr.String(), failed[0].Address)
 		assert.Equal(t, conn.driverConnectionID, failed[0].ConnectionID)
 		assert.Equal(t, requestID, failed[0].RequestID)
-		assert.Equal(t, io.EOF.Error(), failed[0].Reason)
+		assert.Equal(t, "error", failed[0].Reason)
 		assert.ErrorIs(t, failed[0].Error, io.EOF)
 		assert.Equal(t, time.Duration(0), failed[0].RemainingTime)
 
@@ -462,6 +462,7 @@ func TestCMAPProse(t *testing.T) {
 
 		assert.Equal(t, addr.String(), succeeded[0].Address)
 		assert.Equal(t, conn.driverConnectionID, succeeded[0].ConnectionID)
+		assert.Equal(t, requestID, succeeded[0].RequestID)
 		assert.Greater(t, int(succeeded[0].Duration), 0)
 	})
 }

x/mongo/driver/topology/connection.go

@@ -50,7 +50,6 @@ func nextConnectionID() uint64 { return atomic.AddUint64(&globalConnectionID, 1)
 type pendingReadState struct {
 	remainingBytes int32
 	requestID      int32
-	remainingTime  *time.Duration
 	start          time.Time
 }
 

x/mongo/driver/topology/pool.go

@@ -827,29 +827,32 @@ func publishPendingReadFailed(pool *pool, conn *connection, err error) {
 		return
 	}
 
+	reason := event.ReasonError
+	if errors.Is(err, context.DeadlineExceeded) {
+		reason = event.ReasonTimedOut
+	}
+
 	if mustLogPoolMessage(pool) {
 		keysAndValues := logger.KeyValues{
 			logger.KeyDriverConnectionID, conn.driverConnectionID,
 			logger.KeyRequestID, prs.requestID,
-			logger.KeyReason, err.Error(),
-			logger.KeyRemainingTimeMS, *prs.remainingTime,
+			logger.KeyReason, reason,
+			logger.KeyError, err.Error(),
 		}
 
 		logPoolMessage(pool, logger.ConnectionPendingReadFailed, keysAndValues...)
 	}
 
 	if pool.monitor != nil {
-		event := &event.PoolEvent{
+		e := &event.PoolEvent{
 			Type:         event.ConnectionPendingResponseFailed,
 			Address:      pool.address.String(),
 			ConnectionID: conn.driverConnectionID,
 			RequestID:    prs.requestID,
-			//RemainingTime: remainingTime,
-			Reason: err.Error(),
-			Error:  err,
+			Reason:       reason,
+			Error:        err,
 		}
-
-		pool.monitor.Event(event)
+		pool.monitor.Event(e)
 	}
 }
 
@@ -863,6 +866,7 @@ func publishPendingReadSucceeded(pool *pool, conn *connection, dur time.Duration
 		keysAndValues := logger.KeyValues{
 			logger.KeyDriverConnectionID, conn.driverConnectionID,
 			logger.KeyRequestID, prs.requestID,
+			logger.KeyDurationMS, dur.Milliseconds(),
 		}
 
 		logPoolMessage(pool, logger.ConnectionPendingReadSucceeded, keysAndValues...)
@@ -873,6 +877,7 @@ func publishPendingReadSucceeded(pool *pool, conn *connection, dur time.Duration
 			Type:         event.ConnectionPendingResponseSucceeded,
 			Address:      pool.address.String(),
 			ConnectionID: conn.driverConnectionID,
+			RequestID:    prs.requestID,
 			Duration:     dur,
 		}