From 97ce13cdb499aad7d68644c16f385e3b0b5d55e1 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Tue, 29 Aug 2023 16:00:25 -0600 Subject: [PATCH 1/8] GODRIVER-2943 Re-organize client entity expected log messages --- mongo/integration/unified/client_entity.go | 5 +- mongo/integration/unified/context.go | 34 ++++++++-- mongo/integration/unified/logger.go | 40 ++++++++---- .../unified/logger_verification.go | 20 +----- .../unified/logger_verification_test.go | 62 ------------------- .../unified/unified_spec_runner.go | 8 +-- x/mongo/driver/topology/server.go | 4 +- 7 files changed, 65 insertions(+), 108 deletions(-) diff --git a/mongo/integration/unified/client_entity.go b/mongo/integration/unified/client_entity.go index e63c891039..80fa34f0b7 100644 --- a/mongo/integration/unified/client_entity.go +++ b/mongo/integration/unified/client_entity.go @@ -106,7 +106,10 @@ func newClientEntity(ctx context.Context, em *EntityMap, entityOptions *entityOp } if olm := entityOptions.ObserveLogMessages; olm != nil { - clientLogger := newLogger(olm, expectedLogMessageCount(ctx)) + expectedLogMessagesCount := expectedLogMessagesCount(ctx, entityOptions.ID) + ignoreLogMessages := ignoreLogMessages(ctx, entityOptions.ID) + + clientLogger := newLogger(olm, expectedLogMessagesCount, ignoreLogMessages) wrap := func(str string) options.LogLevel { return options.LogLevel(logger.ParseLevel(str)) diff --git a/mongo/integration/unified/context.go b/mongo/integration/unified/context.go index d97abaf023..10cfd00652 100644 --- a/mongo/integration/unified/context.go +++ b/mongo/integration/unified/context.go @@ -28,8 +28,8 @@ const ( failPointsKey ctxKey = "test-failpoints" // targetedFailPointsKey is used to store a map from a fail point name to the host on which the fail point is set. targetedFailPointsKey ctxKey = "test-targeted-failpoints" - // expectedLogMessageCountKey is used to store the number of log messages expected to be received by the test runner. - expectedLogMessageCountKey ctxKey = "test-expected-log-message-count" + clientLogMessagesKey ctxKey = "test-expected-log-message-count" + ignoreLogMessagesKey ctxKey = "test-ignore-log-message-count" ) // newTestContext creates a new Context derived from ctx with values initialized to store the state required for test @@ -37,14 +37,14 @@ const ( func newTestContext( ctx context.Context, entityMap *EntityMap, - expectedLogMessageCount int, + clientLogMessages []*clientLogMessages, hasOperationalFailPoint bool, ) context.Context { ctx = context.WithValue(ctx, operationalFailPointKey, hasOperationalFailPoint) ctx = context.WithValue(ctx, entitiesKey, entityMap) ctx = context.WithValue(ctx, failPointsKey, make(map[string]*mongo.Client)) ctx = context.WithValue(ctx, targetedFailPointsKey, make(map[string]string)) - ctx = context.WithValue(ctx, expectedLogMessageCountKey, expectedLogMessageCount) + ctx = context.WithValue(ctx, clientLogMessagesKey, clientLogMessages) return ctx } @@ -84,6 +84,28 @@ func entities(ctx context.Context) *EntityMap { return ctx.Value(entitiesKey).(*EntityMap) } -func expectedLogMessageCount(ctx context.Context) int { - return ctx.Value(expectedLogMessageCountKey).(int) +func expectedLogMessagesCount(ctx context.Context, clientID string) int { + messages := ctx.Value(clientLogMessagesKey).([]*clientLogMessages) + + count := 0 + for _, message := range messages { + if message.Client == clientID { + count += len(message.LogMessages) + } + } + + return count +} + +func ignoreLogMessages(ctx context.Context, clientID string) []*logMessage { + messages := ctx.Value(clientLogMessagesKey).([]*clientLogMessages) + + ignoreMessages := []*logMessage{} + for _, message := range messages { + if message.Client == clientID { + ignoreMessages = append(ignoreMessages, message.IgnoreMessages...) + } + } + + return ignoreMessages } diff --git a/mongo/integration/unified/logger.go b/mongo/integration/unified/logger.go index 6dcadacf4a..843ac84063 100644 --- a/mongo/integration/unified/logger.go +++ b/mongo/integration/unified/logger.go @@ -7,6 +7,9 @@ package unified import ( + "context" + "fmt" + "go.mongodb.org/mongo-driver/internal/logger" ) @@ -20,20 +23,23 @@ type orderedLogMessage struct { // Logger is the Sink used to captured log messages for logger verification in // the unified spec tests. type Logger struct { - lastOrder int - logQueue chan orderedLogMessage - bufSize int + lastOrder int + logQueue chan orderedLogMessage + bufSize int + ignoreMessages []*logMessage } -func newLogger(olm *observeLogMessages, bufSize int) *Logger { +func newLogger(olm *observeLogMessages, bufSize int, ignoreMessages []*logMessage) *Logger { + fmt.Println("bufSize: ", bufSize) if olm == nil { return nil } return &Logger{ - lastOrder: 1, - logQueue: make(chan orderedLogMessage, bufSize), - bufSize: bufSize, + lastOrder: 1, + logQueue: make(chan orderedLogMessage, bufSize), + bufSize: bufSize, + ignoreMessages: ignoreMessages, } } @@ -44,7 +50,8 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { return } - defer func() { log.lastOrder++ }() + //fmt.Println("ignore list", log.ignoreMessages) + //fmt.Println("log message: ", logMessage) // If the order is greater than the buffer size, we must return. This // would indicate that the logQueue channel has been closed. @@ -61,17 +68,28 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { panic(err) } + for _, ignoreMessage := range log.ignoreMessages { + if err := verifyLogMatch(context.Background(), ignoreMessage, logMessage); err == nil { + return + } + } + + fmt.Println("incoming: ", level, msg) + // Send the log message to the "orderedLogMessage" channel for // validation. log.logQueue <- orderedLogMessage{ order: log.lastOrder + 1, - logMessage: logMessage, - } + logMessage: logMessage} - // If the order has reached the buffer size, then close the channe. + // If the order has reached the buffer size, then close the channel. if log.lastOrder == log.bufSize { close(log.logQueue) } + + fmt.Println(" sent") + + log.lastOrder++ } // Error implements the logger.Sink interface's "Error" method for printing log diff --git a/mongo/integration/unified/logger_verification.go b/mongo/integration/unified/logger_verification.go index 2b8e4e9d11..ec4b78abc0 100644 --- a/mongo/integration/unified/logger_verification.go +++ b/mongo/integration/unified/logger_verification.go @@ -79,17 +79,6 @@ type clientLogMessages struct { LogMessages []*logMessage `bson:"messages"` } -// ignore checks to see if the message is in the "IgnoreMessages" slice. -func (clm clientLogMessages) ignore(ctx context.Context, msg *logMessage) bool { - for _, ignoreMessage := range clm.IgnoreMessages { - if err := verifyLogMatch(ctx, ignoreMessage, msg); err == nil { - return true - } - } - - return false -} - // logMessageValidator defines the expectation for log messages across all // clients. type logMessageValidator struct { @@ -191,8 +180,7 @@ type logQueues struct { } // partitionLogQueue will partition the expected logs into "unordered" and -// "ordered" log channels. This function will also remove any logs in the -// "ignoreMessages" list for a client. +// "ordered" log channels. func partitionLogQueue(ctx context.Context, exp *clientLogMessages) logQueues { orderedLogCh := make(chan *logMessage, len(exp.LogMessages)) unorderedLogCh := make(chan *logMessage, len(exp.LogMessages)) @@ -241,12 +229,6 @@ func matchOrderedLogs(ctx context.Context, logs logQueues) <-chan error { defer close(errs) for actual := range logs.ordered { - // Ignore logs that are in the "IngoreMessages" slice of - // the expected results. - if logs.expected.ignore(ctx, actual) { - continue - } - expected := expLogMessages[0] if expected == nil { continue diff --git a/mongo/integration/unified/logger_verification_test.go b/mongo/integration/unified/logger_verification_test.go index 5defb8d1c0..ebb7f27e68 100644 --- a/mongo/integration/unified/logger_verification_test.go +++ b/mongo/integration/unified/logger_verification_test.go @@ -7,11 +7,8 @@ package unified import ( - "context" "testing" - "go.mongodb.org/mongo-driver/internal/assert" - "go.mongodb.org/mongo-driver/internal/logger" "go.mongodb.org/mongo-driver/internal/require" ) @@ -23,62 +20,3 @@ func newTestLogMessage(t *testing.T, level int, msg string, args ...interface{}) return message } - -func TestClientLogMessagesIgnore(t *testing.T) { - t.Parallel() - - tests := []struct { - name string - clm clientLogMessages - message *logMessage - want bool - }{ - { - name: "empty", - clm: clientLogMessages{}, - message: &logMessage{}, - want: false, - }, - { - name: "no match", - clm: clientLogMessages{ - IgnoreMessages: []*logMessage{ - newTestLogMessage(t, int(logger.LevelDebug), logger.CommandFailed), - }, - }, - message: newTestLogMessage(t, int(logger.LevelInfo), logger.CommandFailed), - want: false, - }, - { - name: "match", - clm: clientLogMessages{ - IgnoreMessages: []*logMessage{ - newTestLogMessage(t, int(logger.LevelDebug), logger.CommandStarted), - }, - }, - message: newTestLogMessage(t, int(logger.LevelDebug), logger.CommandStarted), - want: true, - }, - { - name: "match subset", - clm: clientLogMessages{ - IgnoreMessages: []*logMessage{ - newTestLogMessage(t, int(logger.LevelDebug), logger.CommandStarted), - }, - }, - message: newTestLogMessage(t, int(logger.LevelDebug), logger.CommandStarted, "extrakey", 1), - want: true, - }, - } - - for _, test := range tests { - test := test // capture the range variable - - t.Run(test.name, func(t *testing.T) { - t.Parallel() - - got := test.clm.ignore(context.Background(), test.message) - assert.Equal(t, test.want, got, "clientLogMessages.ignore() result") - }) - } -} diff --git a/mongo/integration/unified/unified_spec_runner.go b/mongo/integration/unified/unified_spec_runner.go index 1b1cbeb533..c62e52cc2a 100644 --- a/mongo/integration/unified/unified_spec_runner.go +++ b/mongo/integration/unified/unified_spec_runner.go @@ -223,13 +223,7 @@ func (tc *TestCase) Run(ls LoggerSkipper) error { return fmt.Errorf("schema version %q not supported: %v", tc.schemaVersion, err) } - // Count the number of expected log messages over all clients. - expectedLogCount := 0 - for _, clientLog := range tc.ExpectLogMessages { - expectedLogCount += len(clientLog.LogMessages) - } - - testCtx := newTestContext(context.Background(), tc.entities, expectedLogCount, tc.setsFailPoint()) + testCtx := newTestContext(context.Background(), tc.entities, tc.ExpectLogMessages, tc.setsFailPoint()) defer func() { // If anything fails while doing test cleanup, we only log the error because the actual test may have already diff --git a/x/mongo/driver/topology/server.go b/x/mongo/driver/topology/server.go index 600797df40..1b8dc7b74a 100644 --- a/x/mongo/driver/topology/server.go +++ b/x/mongo/driver/topology/server.go @@ -1023,10 +1023,10 @@ func (s *Server) publishServerHeartbeatSucceededEvent(connectionID string, } if mustLogServerMessage(s) { - logServerMessage(s, logger.TopologyServerHeartbeatStarted, + logServerMessage(s, logger.TopologyServerHeartbeatSucceeded, logger.KeyAwaited, await, logger.KeyDurationMS, duration.Milliseconds(), - logger.KeyReply, desc) + logger.KeyReply, desc.String()) } } From 9460e670c5d4f1fb13b81e8258e49fc17df3ce82 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Tue, 29 Aug 2023 16:02:03 -0600 Subject: [PATCH 2/8] GODRIVER-2943 Remove debugging statements --- mongo/integration/unified/logger.go | 9 --------- 1 file changed, 9 deletions(-) diff --git a/mongo/integration/unified/logger.go b/mongo/integration/unified/logger.go index 843ac84063..b1cdd3c325 100644 --- a/mongo/integration/unified/logger.go +++ b/mongo/integration/unified/logger.go @@ -8,7 +8,6 @@ package unified import ( "context" - "fmt" "go.mongodb.org/mongo-driver/internal/logger" ) @@ -30,7 +29,6 @@ type Logger struct { } func newLogger(olm *observeLogMessages, bufSize int, ignoreMessages []*logMessage) *Logger { - fmt.Println("bufSize: ", bufSize) if olm == nil { return nil } @@ -50,9 +48,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { return } - //fmt.Println("ignore list", log.ignoreMessages) - //fmt.Println("log message: ", logMessage) - // If the order is greater than the buffer size, we must return. This // would indicate that the logQueue channel has been closed. if log.lastOrder > log.bufSize { @@ -74,8 +69,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { } } - fmt.Println("incoming: ", level, msg) - // Send the log message to the "orderedLogMessage" channel for // validation. log.logQueue <- orderedLogMessage{ @@ -87,8 +80,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { close(log.logQueue) } - fmt.Println(" sent") - log.lastOrder++ } From 2664591c793c13e47be8ea10d60ddc6650dfe030 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Wed, 30 Aug 2023 13:10:11 -0600 Subject: [PATCH 3/8] GODRIVER-2943 Add 'Ok' to server description --- mongo/description/server.go | 3 +++ .../unified/logger_verification_test.go | 22 ------------------- .../unified/unified_spec_runner.go | 2 -- .../unified/logging-replicaset.json | 16 -------------- .../unified/logging-replicaset.yml | 7 ------ x/mongo/driver/topology/server.go | 5 ++++- 6 files changed, 7 insertions(+), 48 deletions(-) delete mode 100644 mongo/integration/unified/logger_verification_test.go diff --git a/mongo/description/server.go b/mongo/description/server.go index cf39423839..8434fe3d0e 100644 --- a/mongo/description/server.go +++ b/mongo/description/server.go @@ -64,6 +64,7 @@ type Server struct { TopologyVersion *TopologyVersion Kind ServerKind WireVersion *VersionRange + Ok int32 } // NewServer creates a new server description from the given hello command response. @@ -229,6 +230,8 @@ func NewServer(addr address.Address, response bson.Raw) Server { desc.LastError = errors.New("not ok") return desc } + + desc.Ok = okay case "passives": var err error desc.Passives, err = stringSliceFromRawElement(element) diff --git a/mongo/integration/unified/logger_verification_test.go b/mongo/integration/unified/logger_verification_test.go deleted file mode 100644 index ebb7f27e68..0000000000 --- a/mongo/integration/unified/logger_verification_test.go +++ /dev/null @@ -1,22 +0,0 @@ -// Copyright (C) MongoDB, Inc. 2023-present. -// -// Licensed under the Apache License, Version 2.0 (the "License"); you may -// not use this file except in compliance with the License. You may obtain -// a copy of the License at http://www.apache.org/licenses/LICENSE-2.0 - -package unified - -import ( - "testing" - - "go.mongodb.org/mongo-driver/internal/require" -) - -func newTestLogMessage(t *testing.T, level int, msg string, args ...interface{}) *logMessage { - t.Helper() - - message, err := newLogMessage(level, msg, args...) - require.NoError(t, err, "failed to create test log message") - - return message -} diff --git a/mongo/integration/unified/unified_spec_runner.go b/mongo/integration/unified/unified_spec_runner.go index c62e52cc2a..4422606a4a 100644 --- a/mongo/integration/unified/unified_spec_runner.go +++ b/mongo/integration/unified/unified_spec_runner.go @@ -30,8 +30,6 @@ var ( // TODO(GODRIVER-2843): Fix and unskip these test cases. "Find operation with snapshot": "Test fails frequently. See GODRIVER-2843", "Write commands with snapshot session do not affect snapshot reads": "Test fails frequently. See GODRIVER-2843", - // TODO(GODRIVER-2943): Fix and unskip this test case. - "Topology lifecycle": "Test times out. See GODRIVER-2943", } logMessageValidatorTimeout = 10 * time.Millisecond diff --git a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.json b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.json index e6738225cd..8522c14e19 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.json +++ b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.json @@ -220,22 +220,6 @@ } } }, - { - "level": "debug", - "component": "topology", - "data": { - "message": "Topology description changed", - "topologyId": { - "$$exists": true - }, - "previousDescription": { - "$$exists": true - }, - "newDescription": { - "$$exists": true - } - } - }, { "level": "debug", "component": "topology", diff --git a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml index 4644dc1355..5e5d6d085f 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml +++ b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml @@ -109,13 +109,6 @@ tests: topologyId: { $$exists: true } serverHost: { $$type: string } serverPort: { $$type: [int, long] } - - level: debug - component: topology - data: - message: "Topology description changed" - topologyId: { $$exists: true } - previousDescription: { $$exists: true } # ReplicaSet topology - newDescription: { $$exists: true } # unknown topology - level: debug component: topology data: diff --git a/x/mongo/driver/topology/server.go b/x/mongo/driver/topology/server.go index 1b8dc7b74a..8e24cc9431 100644 --- a/x/mongo/driver/topology/server.go +++ b/x/mongo/driver/topology/server.go @@ -15,6 +15,7 @@ import ( "sync/atomic" "time" + "go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson/primitive" "go.mongodb.org/mongo-driver/event" "go.mongodb.org/mongo-driver/internal/logger" @@ -1023,10 +1024,12 @@ func (s *Server) publishServerHeartbeatSucceededEvent(connectionID string, } if mustLogServerMessage(s) { + descRaw, _ := bson.Marshal(desc) + logServerMessage(s, logger.TopologyServerHeartbeatSucceeded, logger.KeyAwaited, await, logger.KeyDurationMS, duration.Milliseconds(), - logger.KeyReply, desc.String()) + logger.KeyReply, bson.Raw(descRaw).String()) } } From d3469cad383563ac67184b65d900c761c4c1a09b Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Wed, 30 Aug 2023 15:27:46 -0600 Subject: [PATCH 4/8] GODRIVER-2943 Remove standalone logs --- .../unified/logging-standalone.json | 16 ---------------- .../unified/logging-standalone.yml | 7 ------- 2 files changed, 23 deletions(-) diff --git a/testdata/server-discovery-and-monitoring/unified/logging-standalone.json b/testdata/server-discovery-and-monitoring/unified/logging-standalone.json index 1ee6dbe899..f27d651afc 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-standalone.json +++ b/testdata/server-discovery-and-monitoring/unified/logging-standalone.json @@ -162,22 +162,6 @@ } } }, - { - "level": "debug", - "component": "topology", - "data": { - "message": "Topology description changed", - "topologyId": { - "$$exists": true - }, - "previousDescription": { - "$$exists": true - }, - "newDescription": { - "$$exists": true - } - } - }, { "level": "debug", "component": "topology", diff --git a/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml b/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml index 95c2676d44..9851c3a1e1 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml +++ b/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml @@ -84,13 +84,6 @@ tests: topologyId: { $$exists: true } serverHost: { $$type: string } serverPort: { $$type: [int, long] } - - level: debug - component: topology - data: - message: "Topology description changed" - topologyId: { $$exists: true } - previousDescription: { $$exists: true } # standalone topology - newDescription: { $$exists: true } # unknown topology - level: debug component: topology data: From 19e73d56f3fab9c9d45c7035f68978e4747c30c9 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Wed, 30 Aug 2023 15:34:54 -0600 Subject: [PATCH 5/8] GODRIVER-2943 Add sync TODO comments --- .../unified/logging-replicaset.yml | 14 ++++++++++++++ .../unified/logging-standalone.yml | 14 ++++++++++++++ 2 files changed, 28 insertions(+) diff --git a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml index 5e5d6d085f..176c4e5e18 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml +++ b/testdata/server-discovery-and-monitoring/unified/logging-replicaset.yml @@ -109,6 +109,20 @@ tests: topologyId: { $$exists: true } serverHost: { $$type: string } serverPort: { $$type: [int, long] } + # TODO(GODRIVER-2967): The following log message has been removed from + # the JSON analogue because it assumes that + # "TopologyDescriptionChangedEvent" should occur when a topolgoy is + # closed. This behavior is not clearly defined anywhere and some + # drivers support and some don't. + # + # Need to sync whenever GODRIVER-2967 is unblocked. + - level: debug + component: topology + data: + message: "Topology description changed" + topologyId: { $$exists: true } + previousDescription: { $$exists: true } # ReplicaSet topology + newDescription: { $$exists: true } # unknown topology - level: debug component: topology data: diff --git a/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml b/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml index 9851c3a1e1..0b378cd2fc 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml +++ b/testdata/server-discovery-and-monitoring/unified/logging-standalone.yml @@ -84,6 +84,20 @@ tests: topologyId: { $$exists: true } serverHost: { $$type: string } serverPort: { $$type: [int, long] } + # TODO(GODRIVER-2967): The following log message has been removed from + # the JSON analogue because it assumes that + # "TopologyDescriptionChangedEvent" should occur when a topolgoy is + # closed. This behavior is not clearly defined anywhere and some + # drivers support and some don't. + # + # Need to sync whenever GODRIVER-2967 is unblocked. + - level: debug + component: topology + data: + message: "Topology description changed" + topologyId: { $$exists: true } + previousDescription: { $$exists: true } # standalone topology + newDescription: { $$exists: true } # unknown topology - level: debug component: topology data: From 171895f94fa0dd2f3c2229ddebf45121a4595aad Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Tue, 10 Oct 2023 10:43:38 -0600 Subject: [PATCH 6/8] GODRIVER-2943 Remove Ok from server --- mongo/description/server.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/mongo/description/server.go b/mongo/description/server.go index 8434fe3d0e..cf39423839 100644 --- a/mongo/description/server.go +++ b/mongo/description/server.go @@ -64,7 +64,6 @@ type Server struct { TopologyVersion *TopologyVersion Kind ServerKind WireVersion *VersionRange - Ok int32 } // NewServer creates a new server description from the given hello command response. @@ -230,8 +229,6 @@ func NewServer(addr address.Address, response bson.Raw) Server { desc.LastError = errors.New("not ok") return desc } - - desc.Ok = okay case "passives": var err error desc.Passives, err = stringSliceFromRawElement(element) From 58cb48e73541c543952941254afab3cd173231c6 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Tue, 10 Oct 2023 21:15:06 -0600 Subject: [PATCH 7/8] GODRIVER-2943 Fix sharded case --- mongo/integration/unified/logger.go | 2 -- .../unified/logging-sharded.json | 16 ---------------- .../unified/logging-sharded.yml | 7 +++++++ x/mongo/driver/topology/server.go | 14 +++++++++++++- 4 files changed, 20 insertions(+), 19 deletions(-) diff --git a/mongo/integration/unified/logger.go b/mongo/integration/unified/logger.go index d082324ada..13f5c75f31 100644 --- a/mongo/integration/unified/logger.go +++ b/mongo/integration/unified/logger.go @@ -83,8 +83,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { } } - defer func() { log.lastOrder++ }() - // Send the log message to the "orderedLogMessage" channel for // validation. log.logQueue <- orderedLogMessage{ diff --git a/testdata/server-discovery-and-monitoring/unified/logging-sharded.json b/testdata/server-discovery-and-monitoring/unified/logging-sharded.json index 61b27f5be0..33e7ec4bfe 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-sharded.json +++ b/testdata/server-discovery-and-monitoring/unified/logging-sharded.json @@ -187,22 +187,6 @@ } } }, - { - "level": "debug", - "component": "topology", - "data": { - "message": "Topology description changed", - "topologyId": { - "$$exists": true - }, - "previousDescription": { - "$$exists": true - }, - "newDescription": { - "$$exists": true - } - } - }, { "level": "debug", "component": "topology", diff --git a/testdata/server-discovery-and-monitoring/unified/logging-sharded.yml b/testdata/server-discovery-and-monitoring/unified/logging-sharded.yml index 34cd3611e2..f175ce0f90 100644 --- a/testdata/server-discovery-and-monitoring/unified/logging-sharded.yml +++ b/testdata/server-discovery-and-monitoring/unified/logging-sharded.yml @@ -97,6 +97,13 @@ tests: topologyId: { $$exists: true } serverHost: { $$type: string } serverPort: { $$type: [int, long] } + # TODO(GODRIVER-2967): The following log message has been removed from + # the JSON analogue because it assumes that + # "TopologyDescriptionChangedEvent" should occur when a topolgoy is + # closed. This behavior is not clearly defined anywhere and some + # drivers support and some don't. + # + # Need to sync whenever GODRIVER-2967 is unblocked. - level: debug component: topology data: diff --git a/x/mongo/driver/topology/server.go b/x/mongo/driver/topology/server.go index f86867fb4a..09466347f9 100644 --- a/x/mongo/driver/topology/server.go +++ b/x/mongo/driver/topology/server.go @@ -1028,7 +1028,19 @@ func (s *Server) publishServerHeartbeatSucceededEvent(connectionID string, } if mustLogServerMessage(s) { - descRaw, _ := bson.Marshal(desc) + descRaw, _ := bson.Marshal(struct { + description.Server `bson:",inline"` + Ok int32 + }{ + Server: desc, + Ok: func() int32 { + if desc.LastError != nil { + return 0 + } + + return 1 + }(), + }) logServerMessage(s, logger.TopologyServerHeartbeatSucceeded, logger.KeyAwaited, await, From ae54e2d7370ed7ec0e699cc0947415572c0e8ce9 Mon Sep 17 00:00:00 2001 From: Preston Vasquez <24281431+prestonvasquez@users.noreply.github.com> Date: Wed, 11 Oct 2023 11:20:48 -0600 Subject: [PATCH 8/8] GODRIVER-2943 Fix race test failure --- mongo/integration/unified/logger.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/mongo/integration/unified/logger.go b/mongo/integration/unified/logger.go index 13f5c75f31..eb9379f9e3 100644 --- a/mongo/integration/unified/logger.go +++ b/mongo/integration/unified/logger.go @@ -55,6 +55,9 @@ func newLogger(olm *observeLogMessages, bufSize int, ignoreMessages []*logMessag // Info implements the logger.Sink interface's "Info" method for printing log // messages. func (log *Logger) Info(level int, msg string, args ...interface{}) { + log.orderMu.Lock() + defer log.orderMu.Unlock() + if log.logQueue == nil { return } @@ -65,9 +68,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { return } - log.orderMu.Lock() - defer log.orderMu.Unlock() - // Add the Diff back to the level, as there is no need to create a // logging offset. level = level + logger.DiffToInfo @@ -83,6 +83,8 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { } } + defer func() { log.lastOrder++ }() + // Send the log message to the "orderedLogMessage" channel for // validation. log.logQueue <- orderedLogMessage{ @@ -93,8 +95,6 @@ func (log *Logger) Info(level int, msg string, args ...interface{}) { if log.lastOrder == log.bufSize { close(log.logQueue) } - - log.lastOrder++ } // Error implements the logger.Sink interface's "Error" method for printing log