Skip to content

Commit bf7c8aa

Browse files
jyeminjyemin
committed
JAVA-2328: Fix regression which created extraneous info-level logging to the org.mongodb.cluster logger
1 parent 56a1ae0 commit bf7c8aa

File tree

3 files changed

+288
-124
lines changed

3 files changed

+288
-124
lines changed

‎driver-core/src/main/com/mongodb/connection/DefaultServerMonitor.java

Lines changed: 65 additions & 39 deletions
Original file line numberDiff line numberDiff line change
@@ -104,11 +104,8 @@ public synchronized void run() {
104104
InternalConnection connection = null;
105105
try {
106106
ServerDescription currentServerDescription = getConnectingServerDescription(null);
107-
Throwable currentException = null;
108107
while (!isClosed) {
109108
ServerDescription previousServerDescription = currentServerDescription;
110-
Throwable previousException = currentException;
111-
currentException = null;
112109
try {
113110
if (connection == null) {
114111
connection = internalConnectionFactory.create(serverId);
@@ -142,14 +139,14 @@ public synchronized void run() {
142139
}
143140
} catch (Throwable t) {
144141
averageRoundTripTime.reset();
145-
currentException = t;
146142
currentServerDescription = getConnectingServerDescription(t);
147143
}
148144

149145
if (!isClosed) {
150146
try {
151-
logStateChange(previousServerDescription, previousException, currentServerDescription, currentException);
152-
sendStateChangedEvent(previousServerDescription, currentServerDescription);
147+
logStateChange(previousServerDescription, currentServerDescription);
148+
serverStateListener.stateChanged(new ChangeEvent<ServerDescription>(previousServerDescription,
149+
currentServerDescription));
153150
} catch (Throwable t) {
154151
LOGGER.warn("Exception in monitor thread during notification of server description state change", t);
155152
}
@@ -191,23 +188,12 @@ private ServerDescription lookupServerDescription(final InternalConnection conne
191188
}
192189
}
193190

194-
private void sendStateChangedEvent(final ServerDescription previousServerDescription,
195-
final ServerDescription currentServerDescription) {
196-
if (stateHasChanged(previousServerDescription, currentServerDescription)) {
197-
serverStateListener.stateChanged(new ChangeEvent<ServerDescription>(previousServerDescription,
198-
currentServerDescription));
199-
}
200-
}
201-
202-
private void logStateChange(final ServerDescription previousServerDescription, final Throwable previousException,
203-
final ServerDescription currentServerDescription, final Throwable currentException) {
204-
// Note that the ServerDescription.equals method does not include the average ping time as part of the comparison,
205-
// so this will not spam the logs too hard.
206-
if (descriptionHasChanged(previousServerDescription, currentServerDescription)
207-
|| exceptionHasChanged(previousException, currentException)) {
208-
if (currentException != null) {
191+
private void logStateChange(final ServerDescription previousServerDescription,
192+
final ServerDescription currentServerDescription) {
193+
if (shouldLogStageChange(previousServerDescription, currentServerDescription)) {
194+
if (currentServerDescription.getException() != null) {
209195
LOGGER.info(format("Exception in monitor thread while connecting to server %s", serverId.getAddress()),
210-
currentException);
196+
currentServerDescription.getException());
211197
} else {
212198
LOGGER.info(format("Monitor thread successfully connected to server with description %s", currentServerDescription));
213199
}
@@ -242,27 +228,67 @@ private long waitForSignalOrTimeout() throws InterruptedException {
242228
}
243229
}
244230

245-
static boolean descriptionHasChanged(final ServerDescription previousServerDescription,
246-
final ServerDescription currentServerDescription) {
247-
return !previousServerDescription.equals(currentServerDescription);
248-
}
231+
static boolean shouldLogStageChange(final ServerDescription previous, final ServerDescription current) {
249232

250-
static boolean stateHasChanged(final ServerDescription previousServerDescription, final ServerDescription currentServerDescription) {
251-
return descriptionHasChanged(previousServerDescription, currentServerDescription)
252-
|| previousServerDescription.getRoundTripTimeNanos() != currentServerDescription.getRoundTripTimeNanos();
253-
}
233+
if (previous.isOk() != current.isOk()) {
234+
return true;
235+
}
236+
if (!previous.getAddress().equals(current.getAddress())) {
237+
return true;
238+
}
239+
if (previous.getCanonicalAddress() != null
240+
? !previous.getCanonicalAddress().equals(current.getCanonicalAddress()) : current.getCanonicalAddress() != null) {
241+
return true;
242+
}
243+
if (!previous.getHosts().equals(current.getHosts())) {
244+
return true;
245+
}
246+
if (!previous.getArbiters().equals(current.getArbiters())) {
247+
return true;
248+
}
249+
if (!previous.getPassives().equals(current.getPassives())) {
250+
return true;
251+
}
252+
if (previous.getPrimary() != null ? !previous.getPrimary().equals(current.getPrimary()) : current.getPrimary() != null) {
253+
return true;
254+
}
255+
if (previous.getSetName() != null ? !previous.getSetName().equals(current.getSetName()) : current.getSetName() != null) {
256+
return true;
257+
}
258+
if (previous.getState() != current.getState()) {
259+
return true;
260+
}
261+
if (!previous.getTagSet().equals(current.getTagSet())) {
262+
return true;
263+
}
264+
if (previous.getType() != current.getType()) {
265+
return true;
266+
}
267+
if (!previous.getVersion().equals(current.getVersion())) {
268+
return true;
269+
}
270+
if (previous.getElectionId() != null
271+
? !previous.getElectionId().equals(current.getElectionId()) : current.getElectionId() != null) {
272+
return true;
273+
}
274+
if (previous.getSetVersion() != null
275+
? !previous.getSetVersion().equals(current.getSetVersion()) : current.getSetVersion() != null) {
276+
return true;
277+
}
254278

255-
static boolean exceptionHasChanged(final Throwable previousException, final Throwable currentException) {
256-
if (currentException == null) {
257-
return previousException != null;
258-
} else if (previousException == null) {
279+
// Compare class equality and message as exceptions rarely override equals
280+
Class<?> thisExceptionClass = previous.getException() != null ? previous.getException().getClass() : null;
281+
Class<?> thatExceptionClass = current.getException() != null ? current.getException().getClass() : null;
282+
if (thisExceptionClass != null ? !thisExceptionClass.equals(thatExceptionClass) : thatExceptionClass != null) {
259283
return true;
260-
} else if (!currentException.getClass().equals(previousException.getClass())) {
284+
}
285+
286+
String thisExceptionMessage = previous.getException() != null ? previous.getException().getMessage() : null;
287+
String thatExceptionMessage = current.getException() != null ? current.getException().getMessage() : null;
288+
if (thisExceptionMessage != null ? !thisExceptionMessage.equals(thatExceptionMessage) : thatExceptionMessage != null) {
261289
return true;
262-
} else if (currentException.getMessage() == null) {
263-
return previousException.getMessage() != null;
264-
} else {
265-
return !currentException.getMessage().equals(previousException.getMessage());
266290
}
291+
292+
return false;
267293
}
268294
}

‎driver-core/src/test/functional/com/mongodb/connection/ServerMonitorSpecification.groovy

Lines changed: 117 additions & 62 deletions
Original file line numberDiff line numberDiff line change
@@ -16,24 +16,28 @@
1616

1717
package com.mongodb.connection
1818

19-
import com.mongodb.MongoException
2019
import com.mongodb.MongoSocketException
2120
import com.mongodb.OperationFunctionalSpecification
2221
import com.mongodb.ServerAddress
22+
import com.mongodb.Tag
23+
import com.mongodb.TagSet
2324
import com.mongodb.operation.CommandReadOperation
2425
import org.bson.BsonDocument
2526
import org.bson.BsonInt32
2627
import org.bson.codecs.BsonDocumentCodec
28+
import org.bson.types.ObjectId
2729

2830
import java.util.concurrent.CountDownLatch
29-
import java.util.concurrent.TimeUnit
3031

31-
import static DefaultServerMonitor.exceptionHasChanged
32-
import static DefaultServerMonitor.stateHasChanged
3332
import static com.mongodb.ClusterFixture.getBinding
3433
import static com.mongodb.ClusterFixture.getCredentialList
3534
import static com.mongodb.ClusterFixture.getPrimary
3635
import static com.mongodb.ClusterFixture.getSslSettings
36+
import static com.mongodb.connection.DefaultServerMonitor.shouldLogStageChange
37+
import static com.mongodb.connection.ServerConnectionState.CONNECTED
38+
import static com.mongodb.connection.ServerConnectionState.CONNECTING
39+
import static com.mongodb.connection.ServerDescription.builder
40+
import static java.util.Arrays.asList
3741

3842
class ServerMonitorSpecification extends OperationFunctionalSpecification {
3943
ServerDescription newDescription
@@ -84,70 +88,121 @@ class ServerMonitorSpecification extends OperationFunctionalSpecification {
8488
newDescription.exception instanceof MongoSocketException
8589
}
8690

87-
def 'should report exception has changed when the current and previous are different'() {
88-
expect:
89-
exceptionHasChanged(null, new NullPointerException())
90-
exceptionHasChanged(new NullPointerException(), null)
91-
exceptionHasChanged(new SocketException(), new SocketException('A message'))
92-
exceptionHasChanged(new SocketException('A message'), new SocketException())
93-
exceptionHasChanged(new SocketException('A message'), new MongoException('A message'))
94-
exceptionHasChanged(new SocketException('A message'), new SocketException('A different message'))
95-
}
91+
def 'should log state change if significant properties have changed'() {
92+
given:
93+
ServerDescription.Builder builder = createBuilder();
94+
ServerDescription description = builder.build();
95+
ServerDescription otherDescription
9696

97-
def 'should report exception has not changed when the current and previous are the same'() {
9897
expect:
99-
!exceptionHasChanged(null, null)
100-
!exceptionHasChanged(new NullPointerException(), new NullPointerException())
101-
!exceptionHasChanged(new MongoException('A message'), new MongoException('A message'))
102-
}
98+
!shouldLogStageChange(description, builder.build())
10399

104-
def 'should report state has changed if descriptions are different'() {
105-
expect:
106-
stateHasChanged(ServerDescription.builder()
107-
.type(ServerType.UNKNOWN)
108-
.state(ServerConnectionState.CONNECTING)
109-
.address(new ServerAddress())
110-
.build(),
111-
ServerDescription.builder()
112-
.type(ServerType.STANDALONE)
113-
.state(ServerConnectionState.CONNECTED)
114-
.address(new ServerAddress())
115-
.roundTripTime(5, TimeUnit.MILLISECONDS)
116-
.build());
117-
}
100+
when:
101+
otherDescription = createBuilder().address(new ServerAddress('localhost:27018')).build();
118102

119-
def 'should report state has changed if latencies are different'() {
120-
expect:
121-
stateHasChanged(ServerDescription.builder()
122-
.type(ServerType.STANDALONE)
123-
.state(ServerConnectionState.CONNECTED)
124-
.address(new ServerAddress())
125-
.roundTripTime(5, TimeUnit.MILLISECONDS)
126-
.build(),
127-
ServerDescription.builder()
128-
.type(ServerType.STANDALONE)
129-
.state(ServerConnectionState.CONNECTED)
130-
.address(new ServerAddress())
131-
.roundTripTime(6, TimeUnit.MILLISECONDS)
132-
.build());
103+
then:
104+
shouldLogStageChange(description, otherDescription)
105+
106+
when:
107+
otherDescription = createBuilder().type(ServerType.STANDALONE).build();
108+
109+
then:
110+
shouldLogStageChange(description, otherDescription)
111+
112+
when:
113+
otherDescription = createBuilder().tagSet(null).build();
114+
115+
then:
116+
shouldLogStageChange(description, otherDescription)
117+
118+
when:
119+
otherDescription = createBuilder().setName('test2').build();
120+
121+
then:
122+
shouldLogStageChange(description, otherDescription)
123+
124+
when:
125+
otherDescription = createBuilder().primary('localhost:27018').build();
126+
127+
then:
128+
shouldLogStageChange(description, otherDescription)
129+
130+
when:
131+
otherDescription = createBuilder().canonicalAddress('localhost:27018').build();
132+
133+
then:
134+
shouldLogStageChange(description, otherDescription)
135+
136+
when:
137+
otherDescription = createBuilder().hosts(new HashSet<String>(asList('localhost:27018'))).build();
138+
139+
then:
140+
shouldLogStageChange(description, otherDescription)
141+
142+
when:
143+
otherDescription = createBuilder().arbiters(new HashSet<String>(asList('localhost:27018'))).build();
144+
145+
then:
146+
shouldLogStageChange(description, otherDescription)
147+
148+
when:
149+
otherDescription = createBuilder().passives(new HashSet<String>(asList('localhost:27018'))).build();
150+
151+
then:
152+
shouldLogStageChange(description, otherDescription)
153+
154+
when:
155+
otherDescription = createBuilder().ok(false).build();
156+
157+
then:
158+
shouldLogStageChange(description, otherDescription)
159+
160+
when:
161+
otherDescription = createBuilder().state(CONNECTING).build();
162+
163+
then:
164+
shouldLogStageChange(description, otherDescription)
165+
166+
when:
167+
otherDescription = createBuilder().version(new ServerVersion(asList(2, 6, 1))).build();
168+
169+
then:
170+
shouldLogStageChange(description, otherDescription)
171+
172+
when:
173+
otherDescription = createBuilder().electionId(new ObjectId()).build();
174+
175+
then:
176+
shouldLogStageChange(description, otherDescription)
177+
178+
when:
179+
otherDescription = createBuilder().setVersion(3).build();
180+
181+
then:
182+
shouldLogStageChange(description, otherDescription)
183+
184+
// test exception state changes
185+
shouldLogStageChange(createBuilder().exception(new IOException()).build(),
186+
createBuilder().exception(new RuntimeException()).build())
187+
shouldLogStageChange(createBuilder().exception(new IOException('message one')).build(),
188+
createBuilder().exception(new IOException('message two')).build())
133189
}
134190

135-
def 'should report state has not changed if descriptions and latencies are the same'() {
136-
expect:
137-
!stateHasChanged(ServerDescription.builder()
138-
.type(ServerType.STANDALONE)
139-
.state(ServerConnectionState.CONNECTED)
140-
.address(new ServerAddress())
141-
.roundTripTime(5, TimeUnit.MILLISECONDS)
142-
.lastUpdateTimeNanos(42L)
143-
.build(),
144-
ServerDescription.builder()
145-
.type(ServerType.STANDALONE)
146-
.state(ServerConnectionState.CONNECTED)
147-
.address(new ServerAddress())
148-
.roundTripTime(5, TimeUnit.MILLISECONDS)
149-
.lastUpdateTimeNanos(42L)
150-
.build());
191+
private static ServerDescription.Builder createBuilder() {
192+
builder().ok(true)
193+
.state(CONNECTED)
194+
.address(new ServerAddress())
195+
.type(ServerType.SHARD_ROUTER)
196+
.tagSet(new TagSet(asList(new Tag('dc', 'ny'))))
197+
.setName('test')
198+
.primary('localhost:27017')
199+
.canonicalAddress('localhost:27017')
200+
.hosts(new HashSet<String>(asList('localhost:27017', 'localhost:27018')))
201+
.passives(new HashSet<String>(asList('localhost:27019')))
202+
.arbiters(new HashSet<String>(asList('localhost:27020')))
203+
.version(new ServerVersion(asList(2, 4, 1)))
204+
.electionId(new ObjectId('abcdabcdabcdabcdabcdabcd'))
205+
.setVersion(2)
151206
}
152207

153208
def initializeServerMonitor(ServerAddress address) {

0 commit comments

Comments
 (0)