com.mongodb.MongoNotPrimaryException

There are no available Samebug tips for this exception. Do you have an idea how to solve this issue? A short tip would help users who saw this issue last week.

  • I posted this to https://groups.google.com/forum/#!topic/mongodb-user/7pAm95sBjgY but no response came (so far). Since this appears to be an actual bug, I'm trying my luck here. This logging is from a connection to a replica set of 3 members (10.0.\{20,21,22}.5, 10.0.22.5 is primary and has been for more than a week). A count query is executed: {noformat} {"$and":[{"tenant":"foo"},{"$and":[{"tenant":{"$regex":".*\\Qfoo\\E.*","$options":"i"}}]}]} {noformat} (uselessly complex, I know) with read preference 'secondary'. The query fails with MongoNotPrimaryException and the connection to the secondary is marked UNKNOWN. Trace logging: {code} 13:18:36.530 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.cluster - Asynchronously selecting server with selector ReadPreferenceServerSelector{readPreference=secondary} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.cluster - Asynchronously selected server 10.0.21.5:27017 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Asynchronously getting a connection from the pool for server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0. 21.5:27017} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Checked out connection [connectionId{localValue:14}] to server 10.0.21.5:27017 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Asynchronously opening pooled connection connectionId{localValue:14} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='nul l'}, address=10.0.21.5:27017} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Pooled connection connectionId{localValue:14} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0.21.5: 27017} is not yet open 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 143. ([connectionId{localValue:14}]) 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 143. ([connectionId{localValue:14}]) 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 143 on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 143 on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 144. ([connectionId{localValue:14}]) 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 144. ([connectionId{localValue:14}]) 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 144 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 144 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 145. ([connectionId{localValue:14}]) 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 145. ([connectionId{localValue:14}]) 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 145 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 145 on connectionId{localValue:14} 13:18:36.534 [Thread-6] INFO org.mongodb.driver.connection - Opened connection [connectionId{localValue:14, serverValue:983}] to 10.0.21.5:27017 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Pooled connection connectionId{localValue:14, serverValue:983} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0.21.5: 27017} is now open 13:18:36.536 [Thread-6] DEBUG org.mongodb.driver.protocol.command - Asynchronously sending command {count : BsonString{value='school'}} to database didditVle on connection [connectionId{localValue:14, serverValue:983}] to server 10.0.21. 5:27017 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 146. ([connectionId{localValue:14, serverValue:983}]) 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 146. ([connectionId{localValue:14, serverValue:983}]) 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] TRACE org.mongodb.driver.connection - Read response to message 146 on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] TRACE org.mongodb.driver.connection - Executing callback for 146 on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] DEBUG org.mongodb.driver.protocol.command - Command execution completed with status false 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.cluster - Updating cluster description to {type=REPLICA_SET, servers=[{address=10.0.20.5:27017, type=REPLICA_SET_SECONDARY, roundTripTime=2.5 ms, state=CONNECTED}, {address=10.0.21.5:2701 7, type=UNKNOWN, state=CONNECTING}, {address=10.0.22.5:27017, type=REPLICA_SET_PRIMARY, roundTripTime=2.0 ms, state=CONNECTED}] 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.connection - Invalidating the connection pool 13:18:36.545 [cluster-ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}-10.0.21.5:27017] DEBUG org.mongodb.driver.connection - Closing connection connectionId{localValue:3, serverValue:965} 13:18:36.545 [Thread-5] TRACE org.mongodb.driver.connection - Checked in connection [connectionId{localValue:14, serverValue:983}] to server 10.0.21.5:27017 13:18:36.545 [Thread-5] INFO org.mongodb.driver.connection - Closed connection [connectionId{localValue:14, serverValue:983}] to 10.0.21.5:27017 because there was a socket exception raised on another connection from this pool. 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.connection - Closing connection connectionId{localValue:14, serverValue:983} 13:18:36.550 [vert.x-eventloop-thread-0] ERROR XXX.MongoConnector - An error occurred com.mongodb.MongoNotPrimaryException: The server is not the primary and did not execute the operation at com.mongodb.connection.ProtocolHelper.createSpecialException(ProtocolHelper.java:121) ~[mongo-java-driver-3.0.3.jar:na] {code} Apart from the issue with the count query explained above, I have experienced the same issue with a find query today.
    via by Jens Geiregat,
  • I posted this to https://groups.google.com/forum/#!topic/mongodb-user/7pAm95sBjgY but no response came (so far). Since this appears to be an actual bug, I'm trying my luck here. This logging is from a connection to a replica set of 3 members (10.0.\{20,21,22}.5, 10.0.22.5 is primary and has been for more than a week). A count query is executed: {noformat} {"$and":[{"tenant":"foo"},{"$and":[{"tenant":{"$regex":".*\\Qfoo\\E.*","$options":"i"}}]}]} {noformat} (uselessly complex, I know) with read preference 'secondary'. The query fails with MongoNotPrimaryException and the connection to the secondary is marked UNKNOWN. Trace logging: {code} 13:18:36.530 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.cluster - Asynchronously selecting server with selector ReadPreferenceServerSelector{readPreference=secondary} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.cluster - Asynchronously selected server 10.0.21.5:27017 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Asynchronously getting a connection from the pool for server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0. 21.5:27017} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Checked out connection [connectionId{localValue:14}] to server 10.0.21.5:27017 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Asynchronously opening pooled connection connectionId{localValue:14} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='nul l'}, address=10.0.21.5:27017} 13:18:36.531 [vert.x-eventloop-thread-0] TRACE org.mongodb.driver.connection - Pooled connection connectionId{localValue:14} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0.21.5: 27017} is not yet open 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 143. ([connectionId{localValue:14}]) 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 143. ([connectionId{localValue:14}]) 13:18:36.532 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 143 on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 143 on connectionId{localValue:14} 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 144. ([connectionId{localValue:14}]) 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 144. ([connectionId{localValue:14}]) 13:18:36.533 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 144 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 144 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 145. ([connectionId{localValue:14}]) 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 145. ([connectionId{localValue:14}]) 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Read response to message 145 on connectionId{localValue:14} 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Executing callback for 145 on connectionId{localValue:14} 13:18:36.534 [Thread-6] INFO org.mongodb.driver.connection - Opened connection [connectionId{localValue:14, serverValue:983}] to 10.0.21.5:27017 13:18:36.534 [Thread-6] TRACE org.mongodb.driver.connection - Pooled connection connectionId{localValue:14, serverValue:983} to server ServerId{clusterId=ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}, address=10.0.21.5: 27017} is now open 13:18:36.536 [Thread-6] DEBUG org.mongodb.driver.protocol.command - Asynchronously sending command {count : BsonString{value='school'}} to database didditVle on connection [connectionId{localValue:14, serverValue:983}] to server 10.0.21. 5:27017 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Queuing send message: 146. ([connectionId{localValue:14, serverValue:983}]) 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Queuing read message: 146. ([connectionId{localValue:14, serverValue:983}]) 13:18:36.537 [Thread-6] TRACE org.mongodb.driver.connection - Start receiving response on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] TRACE org.mongodb.driver.connection - Read response to message 146 on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] TRACE org.mongodb.driver.connection - Executing callback for 146 on connectionId{localValue:14, serverValue:983} 13:18:36.538 [Thread-5] DEBUG org.mongodb.driver.protocol.command - Command execution completed with status false 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.cluster - Updating cluster description to {type=REPLICA_SET, servers=[{address=10.0.20.5:27017, type=REPLICA_SET_SECONDARY, roundTripTime=2.5 ms, state=CONNECTED}, {address=10.0.21.5:2701 7, type=UNKNOWN, state=CONNECTING}, {address=10.0.22.5:27017, type=REPLICA_SET_PRIMARY, roundTripTime=2.0 ms, state=CONNECTED}] 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.connection - Invalidating the connection pool 13:18:36.545 [cluster-ClusterId{value='55eec3134ce4b505fd7a76e8', description='null'}-10.0.21.5:27017] DEBUG org.mongodb.driver.connection - Closing connection connectionId{localValue:3, serverValue:965} 13:18:36.545 [Thread-5] TRACE org.mongodb.driver.connection - Checked in connection [connectionId{localValue:14, serverValue:983}] to server 10.0.21.5:27017 13:18:36.545 [Thread-5] INFO org.mongodb.driver.connection - Closed connection [connectionId{localValue:14, serverValue:983}] to 10.0.21.5:27017 because there was a socket exception raised on another connection from this pool. 13:18:36.545 [Thread-5] DEBUG org.mongodb.driver.connection - Closing connection connectionId{localValue:14, serverValue:983} 13:18:36.550 [vert.x-eventloop-thread-0] ERROR XXX.MongoConnector - An error occurred com.mongodb.MongoNotPrimaryException: The server is not the primary and did not execute the operation at com.mongodb.connection.ProtocolHelper.createSpecialException(ProtocolHelper.java:121) ~[mongo-java-driver-3.0.3.jar:na] {code} Apart from the issue with the count query explained above, I have experienced the same issue with a find query today.
    via by Jens Geiregat,
    • com.mongodb.MongoNotPrimaryException: The server is not the primary and did not execute the operation at com.mongodb.connection.ProtocolHelper.createSpecialException(ProtocolHelper.java:121)[mongo-java-driver-3.0.3.jar:na]
    No Bugmate found.