Uploaded image for project: 'Jackrabbit Oak'
  1. Jackrabbit Oak
  2. OAK-5545

Replica Set Info seems to close and open Mongo connections in a loop

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.5.18
    • Fix Version/s: 1.6.0
    • Component/s: mongomk
    • Labels:
      None

      Description

      The Replica Set Info should keep a pool of direct connections to each replica set member (so it can get the recent info about the replicated revisions). It’s maintained by NodeCollectionProvider. It seems that the connection are being closed, even though they are still used:

      24.01.2017 13:33:42.238 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.cluster Cluster created with settings {hosts=[10.40.66.214:27019], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
      24.01.2017 13:33:42.239 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.cluster No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=UNKNOWN, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=10.40.66.214:27019, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out
      24.01.2017 13:33:42.241 *INFO* [cluster-ClusterId{value='58870a5e30806985f2fc331e', description='null'}-10.40.66.214:27019] org.mongodb.driver.connection Opened connection [connectionId{localValue:3190, serverValue:32190}] to 10.40.66.214:27019
      24.01.2017 13:33:42.241 *INFO* [cluster-ClusterId{value='58870a5e30806985f2fc331e', description='null'}-10.40.66.214:27019] org.mongodb.driver.cluster Monitor thread successfully connected to server with description ServerDescription{address=10.40.66.214:27019, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 1]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=452055, setName='replica', canonicalAddress=10.40.66.214:27019, hosts=[no1010040066196.corp.adobe.com:27019, 10.40.66.214:27019, 10.40.66.183:27019], passives=[], arbiters=[], primary='10.40.66.214:27019', tagSet=TagSet{[]}, electionId=57c968610000000000000005, setVersion=3, lastWriteDate=null, lastUpdateTimeNanos=14416412141118257}
      24.01.2017 13:33:42.244 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.connection Opened connection [connectionId{localValue:3191, serverValue:32191}] to 10.40.66.214:27019
      24.01.2017 13:33:42.245 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.connection Closed connection [connectionId{localValue:3191, serverValue:32191}] to 10.40.66.214:27019 because the pool has been closed.
      24.01.2017 13:33:47.248 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.cluster Cluster created with settings {hosts=[10.40.66.214:27019], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
      24.01.2017 13:33:47.249 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.cluster No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=UNKNOWN, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=10.40.66.214:27019, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out
      24.01.2017 13:33:47.264 *INFO* [cluster-ClusterId{value='58870a6330806985f2fc331f', description='null'}-10.40.66.214:27019] org.mongodb.driver.connection Opened connection [connectionId{localValue:3192, serverValue:32194}] to 10.40.66.214:27019
      24.01.2017 13:33:47.265 *INFO* [cluster-ClusterId{value='58870a6330806985f2fc331f', description='null'}-10.40.66.214:27019] org.mongodb.driver.cluster Monitor thread successfully connected to server with description ServerDescription{address=10.40.66.214:27019, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 1]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=416028, setName='replica', canonicalAddress=10.40.66.214:27019, hosts=[no1010040066196.corp.adobe.com:27019, 10.40.66.214:27019, 10.40.66.183:27019], passives=[], arbiters=[], primary='10.40.66.214:27019', tagSet=TagSet{[]}, electionId=57c968610000000000000005, setVersion=3, lastWriteDate=null, lastUpdateTimeNanos=14416417164730588}
      24.01.2017 13:33:47.268 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.connection Opened connection [connectionId{localValue:3193, serverValue:32195}] to 10.40.66.214:27019
      24.01.2017 13:33:47.269 *INFO* [MongoDocumentStore replica set info provider (0)] org.mongodb.driver.connection Closed connection [connectionId{localValue:3193, serverValue:32195}] to 10.40.66.214:27019 because the pool has been closed.
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                tomek.rekawek Tomek Rękawek
                Reporter:
                tomek.rekawek Tomek Rękawek
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: