JAVA-836: Changed logic for logging of up and down servers. Now the background thread logs on every state change, which will reduce log spamming dramatically.

Author: jyemin

src/main/com/mongodb/ConnectionStatus.java

@@ -15,12 +15,15 @@
  */
 package com.mongodb;
 
-import java.io.IOException;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.logging.Level;
 import java.util.logging.Logger;
 
+import static com.mongodb.ConnectionStatus.UpdatableNode.ConnectionState.Connected;
+import static com.mongodb.ConnectionStatus.UpdatableNode.ConnectionState.Connecting;
+import static com.mongodb.ConnectionStatus.UpdatableNode.ConnectionState.Unconnected;
+
 /**
  * Base class for classes that manage connections to mongo instances as background tasks.
  */
@@ -171,68 +174,53 @@ public BackgroundUpdater(final String name) {
     }
 
     static abstract class UpdatableNode {
+
+        enum ConnectionState {
+            Connecting, Connected, Unconnected
+        }
+
         UpdatableNode(final ServerAddress addr, Mongo mongo, MongoOptions mongoOptions) {
             this._addr = addr;
             this._mongo = mongo;
             this._mongoOptions = mongoOptions;
             this._port = new DBPort(addr, null, mongoOptions);
         }
 
+        public boolean isOk() {
+            return _connectionState == Connected;
+        }
+
         public CommandResult update() {
-            CommandResult res = null;
             try {
                 long start = System.nanoTime();
-                res = _port.runCommand(_mongo.getDB("admin"), isMasterCmd);
+                CommandResult res = _port.runCommand(_mongo.getDB("admin"), isMasterCmd);
+
                 long end = System.nanoTime();
                 float newPingMS = (end - start) / 1000000F;
-                if (!successfullyContacted)
+                if (_connectionState != Connected) {
                     _pingTimeMS = newPingMS;
-                else
+                }
+                else {
                     _pingTimeMS = _pingTimeMS + ((newPingMS - _pingTimeMS) / latencySmoothFactor);
-
-                getLogger().log(Level.FINE, "Latency to " + _addr + " actual=" + newPingMS + " smoothed=" + _pingTimeMS);
-
-                successfullyContacted = true;
-
-                if (res == null) {
-                    throw new MongoInternalException("Invalid null value returned from isMaster");
                 }
 
-                if (!_ok) {
-                    getLogger().log(Level.INFO, "Server seen up: " + _addr);
-                }
-                _ok = true;
+                _maxBsonObjectSize = res.getInt("maxBsonObjectSize", Bytes.MAX_OBJECT_SIZE);
 
-                // max size was added in 1.8
-                if (res.containsField("maxBsonObjectSize")) {
-                    _maxBsonObjectSize = (Integer) res.get("maxBsonObjectSize");
-                } else {
-                    _maxBsonObjectSize = Bytes.MAX_OBJECT_SIZE;
-                }
-            } catch (Exception e) {
-                if (!((_ok) ? true : (Math.random() > 0.1))) {
-                    return res;
+                if (_connectionState != Connected) {
+                    _connectionState = Connected;
+                    getLogger().log(Level.INFO, "Server seen up: " + _addr);
                 }
 
-                final StringBuilder logError = (new StringBuilder("Server seen down: ")).append(_addr);
-
-                if (e instanceof IOException) {
-
-                    logError.append(" - ").append(IOException.class.getName());
-
-                    if (e.getMessage() != null) {
-                        logError.append(" - message: ").append(e.getMessage());
-                    }
-
-                    getLogger().log(Level.WARNING, logError.toString());
+                getLogger().log(Level.FINE, "Latency to " + _addr + " actual=" + newPingMS + " smoothed=" + _pingTimeMS);
 
-                } else {
-                    getLogger().log(Level.WARNING, logError.toString(), e);
+                return res;
+            } catch (Exception e) {
+                if (_connectionState != Unconnected) {
+                    _connectionState = Unconnected;
+                    getLogger().log(Level.WARNING, String.format("Server seen down: %s", _addr), e);
                 }
-                _ok = false;
+                return null;
             }
-
-            return res;
         }
 
         protected abstract Logger getLogger();
@@ -243,10 +231,9 @@ public CommandResult update() {
 
         DBPort _port; // we have our own port so we can set different socket options and don't have to worry about the pool
 
-        boolean successfullyContacted = false;
-        boolean _ok = false;
         float _pingTimeMS = 0;
         int _maxBsonObjectSize;
+        ConnectionState _connectionState = Connecting;
     }
 
 }

src/main/com/mongodb/DynamicConnectionStatus.java

@@ -112,7 +112,7 @@ public void run() {
                             while (!Thread.interrupted()) {
                                 try {
                                     node.update();
-                                    if (node._ok) {
+                                    if (node.isOk()) {
                                         notifyOfOkNode(node);
                                         return;
                                     }

src/main/com/mongodb/MongosStatus.java

@@ -64,7 +64,7 @@ public void run() {
                         MongosNode bestThisPass = null;
                         for (MongosNode cur : mongosNodes) {
                             cur.update();
-                            if (cur._ok) {
+                            if (cur.isOk()) {
                                 if (bestThisPass == null || (cur._pingTimeMS < bestThisPass._pingTimeMS)) {
                                     bestThisPass = cur;
                                 }
@@ -109,7 +109,7 @@ private synchronized void setPreferred(final MongosNode bestThisPass) {
         if (bestThisPass == null) {
             preferred = null;
         } else {
-            preferred = new Node(bestThisPass._pingTimeMS, bestThisPass._addr, bestThisPass._maxBsonObjectSize, bestThisPass._ok);
+            preferred = new Node(bestThisPass._pingTimeMS, bestThisPass._addr, bestThisPass._maxBsonObjectSize, bestThisPass.isOk());
         }
         notifyAll();
     }

src/main/com/mongodb/ReplicaSetStatus.java

@@ -601,7 +601,7 @@ private void updateAddr() {
 
         void update(Set<UpdatableReplicaSetNode> seenNodes) {
             CommandResult res = update();
-            if (res == null || !_ok) {
+            if (res == null || !isOk()) {
                 return;
             }
 
@@ -769,7 +769,7 @@ public synchronized void updateAll(){
         private List<ReplicaSetNode> createNodeList() {
             List<ReplicaSetNode> nodeList = new ArrayList<ReplicaSetNode>(_all.size());
             for (UpdatableReplicaSetNode cur : _all) {
-                nodeList.add(new ReplicaSetNode(cur._addr, cur._names, cur._setName, cur._pingTimeMS, cur._ok, cur._isMaster, cur._isSecondary, cur._tags, cur._maxBsonObjectSize));
+                nodeList.add(new ReplicaSetNode(cur._addr, cur._names, cur._setName, cur._pingTimeMS, cur.isOk(), cur._isMaster, cur._isSecondary, cur._tags, cur._maxBsonObjectSize));
             }
             return nodeList;
         }

src/test/com/mongodb/ReplicaSetStatusDomainModelTest.java

@@ -11,6 +11,8 @@
 import java.util.concurrent.atomic.AtomicReference;
 import java.util.logging.Logger;
 
+import static com.mongodb.ConnectionStatus.UpdatableNode.ConnectionState.Connected;
+
 /**
  * Copyright (c) 2008 - 2011 10gen, Inc. <http://10gen.com>
  * <p/>
@@ -240,7 +242,7 @@ private void addNodeToLists(String address, boolean isSecondary, float pingTime,
         ServerAddress serverAddress = new ServerAddress(address);
         ReplicaSetStatus.UpdatableReplicaSetNode updatableNode
                 = new ReplicaSetStatus.UpdatableReplicaSetNode(serverAddress, updatableNodes, _logger, null, _mongoOptions, _lastPrimarySignal);
-        updatableNode._ok = true;
+        updatableNode._connectionState = Connected;
         updatableNode._pingTimeMS = pingTime;
         updatableNode._isSecondary = isSecondary;
         updatableNode._isMaster = !isSecondary;