[JAVA-3616] java.lang.IllegalStateException: Attempted to decrement the reference count below 0 Created: 03/Feb/20  Updated: 16/Mar/20  Resolved: 13/Mar/20

Status: Closed
Project: Java Driver
Component/s: Test Failure
Affects Version/s: 3.12.1
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Ross Lawley Assignee: Ross Lawley
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates JAVA-3647 Race condition between closing a conn... Closed

 Description   

Seen on evergreen:

FAILURE: com.mongodb.MongoSocketClosedException: Can not read from a closed socket (com.mongodb.MongoSocketClosedException)
 com.mongodb.MongoSocketClosedException: Can not read from a closed socket
 	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceiveAsync(InternalStreamConnection.java:320)
 	at com.mongodb.internal.connection.UsageTrackingInternalConnection.sendAndReceiveAsync(UsageTrackingInternalConnection.java:114)
 	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.sendAndReceiveAsync(DefaultConnectionPool.java:511)
 	at com.mongodb.internal.connection.CommandProtocolImpl.executeAsync(CommandProtocolImpl.java:77)
 	at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.executeAsync(DefaultServer.java:239)
 	at com.mongodb.internal.connection.DefaultServerConnection.executeProtocolAsync(DefaultServerConnection.java:218)
 	at com.mongodb.internal.connection.DefaultServerConnection.commandAsync(DefaultServerConnection.java:135)
 	at com.mongodb.internal.connection.DefaultServerConnection.commandAsync(DefaultServerConnection.java:126)
 	at com.mongodb.internal.operation.CommandOperationHelper.executeCommandAsync(CommandOperationHelper.java:647)
 	at com.mongodb.internal.operation.CommandOperationHelper.executeCommandAsync(CommandOperationHelper.java:636)
 	at com.mongodb.internal.operation.DropCollectionOperation$2.call(DropCollectionOperation.java:114)
 	at com.mongodb.internal.operation.OperationHelper$6.onResult(OperationHelper.java:599)
 	at com.mongodb.internal.operation.OperationHelper$6.onResult(OperationHelper.java:592)
 	at com.mongodb.internal.connection.DefaultServer$1.onResult(DefaultServer.java:114)
 	at com.mongodb.internal.connection.DefaultServer$1.onResult(DefaultServer.java:103)
 	at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:48)
 	at com.mongodb.internal.connection.DefaultConnectionPool.openAsync(DefaultConnectionPool.java:201)
 	at com.mongodb.internal.connection.DefaultConnectionPool.getAsync(DefaultConnectionPool.java:156)
 	at com.mongodb.internal.connection.DefaultServer.getConnectionAsync(DefaultServer.java:103)
 	at com.mongodb.internal.binding.AsyncClusterBinding$AsyncClusterBindingConnectionSource.getConnection(AsyncClusterBinding.java:124)
 	at com.mongodb.internal.async.client.ClientSessionBinding$SessionBindingAsyncConnectionSource.getConnection(ClientSessionBinding.java:173)
 	at com.mongodb.internal.operation.OperationHelper.withAsyncConnectionSourceCallableConnection(OperationHelper.java:592)
 	at com.mongodb.internal.operation.OperationHelper.access$000(OperationHelper.java:62)
 	at com.mongodb.internal.operation.OperationHelper$AsyncCallableWithConnectionCallback.onResult(OperationHelper.java:570)
 	at com.mongodb.internal.operation.OperationHelper$AsyncCallableWithConnectionCallback.onResult(OperationHelper.java:560)
 	at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:48)
 	at com.mongodb.internal.async.client.ClientSessionBinding.wrapConnectionSource(ClientSessionBinding.java:107)
 	at com.mongodb.internal.async.client.ClientSessionBinding.access$000(ClientSessionBinding.java:36)
 	at com.mongodb.internal.async.client.ClientSessionBinding$2.onResult(ClientSessionBinding.java:75)
 	at com.mongodb.internal.async.client.ClientSessionBinding$2.onResult(ClientSessionBinding.java:69)
 	at com.mongodb.internal.binding.AsyncClusterBinding$1.onResult(AsyncClusterBinding.java:98)
 	at com.mongodb.internal.binding.AsyncClusterBinding$1.onResult(AsyncClusterBinding.java:92)
 	at com.mongodb.internal.connection.BaseCluster$ServerSelectionRequest.onResult(BaseCluster.java:428)
 	at com.mongodb.internal.connection.BaseCluster.handleServerSelectionRequest(BaseCluster.java:299)
 	at com.mongodb.internal.connection.BaseCluster.selectServerAsync(BaseCluster.java:155)
 	at com.mongodb.internal.connection.AbstractMultiServerCluster.selectServerAsync(AbstractMultiServerCluster.java:54)
 	at com.mongodb.internal.binding.AsyncClusterBinding.getAsyncClusterBindingConnectionSource(AsyncClusterBinding.java:92)
 	at com.mongodb.internal.binding.AsyncClusterBinding.getWriteConnectionSource(AsyncClusterBinding.java:87)
 	at com.mongodb.internal.async.client.ClientSessionBinding.getWriteConnectionSource(ClientSessionBinding.java:69)
 	at com.mongodb.internal.operation.OperationHelper.withAsyncConnection(OperationHelper.java:545)
 	at com.mongodb.internal.operation.DropCollectionOperation.executeAsync(DropCollectionOperation.java:106)
 	at com.mongodb.internal.async.client.OperationExecutorImpl$2$1.onResult(OperationExecutorImpl.java:132)
 	at com.mongodb.internal.async.client.OperationExecutorImpl$2$1.onResult(OperationExecutorImpl.java:126)
 	at com.mongodb.internal.async.client.OperationExecutorImpl.getReadWriteBinding(OperationExecutorImpl.java:182)
 	at com.mongodb.internal.async.client.OperationExecutorImpl.access$200(OperationExecutorImpl.java:43)
 	at com.mongodb.internal.async.client.OperationExecutorImpl$2.onResult(OperationExecutorImpl.java:124)
 	at com.mongodb.internal.async.client.OperationExecutorImpl$2.onResult(OperationExecutorImpl.java:118)
 	at com.mongodb.internal.async.client.ClientSessionHelper.createClientSession(ClientSessionHelper.java:63)
 	at com.mongodb.internal.async.client.ClientSessionHelper.withClientSession(ClientSessionHelper.java:53)
 	at com.mongodb.internal.async.client.OperationExecutorImpl.execute(OperationExecutorImpl.java:118)
 	at com.mongodb.internal.async.client.AsyncMongoCollectionImpl.executeDrop(AsyncMongoCollectionImpl.java:859)
 	at com.mongodb.internal.async.client.AsyncMongoCollectionImpl.drop(AsyncMongoCollectionImpl.java:849)
 	at groovy.lang.Closure.call(Closure.java:418)
 	at groovy.lang.Closure.call(Closure.java:434)
 	at com.mongodb.internal.async.client.TestHelper.runOp(TestHelper.groovy:37)
 	at com.mongodb.internal.async.client.TestHelper.run(TestHelper.groovy:27)
 	at com.mongodb.internal.async.client.gridfs.AsyncGridFSBucketSmokeTestSpecification.setup(AsyncGridFSBucketSmokeTestSpecification.groovy:58)
 system-out:
 10:44:15.070 [Test worker] INFO  org.mongodb.driver.cluster - Cluster created with settings {hosts=[localhost:27017, localhost:27018, localhost:27019], mode=MULTIPLE, requiredClusterType=REPLICA_SET, serverSelectionTimeout='30000 ms', requiredReplicaSetName='repl0'}
10:44:15.074 [Test worker] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27017 to client view of cluster
10:44:15.095 [Test worker] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27018 to client view of cluster
10:44:15.096 [Test worker] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27019 to client view of cluster
10:44:15.169 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27019] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:2, serverValue:24}] to localhost:27019
10:44:15.171 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27017] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:1, serverValue:31}] to localhost:27017
10:44:15.173 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:3, serverValue:35}] to localhost:27018
10:44:15.181 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=5527982, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169133504636}
10:44:15.182 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27018, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=5674129, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=7fffffff0000000000000001, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169135918507}
10:44:15.183 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Setting max election id to 7fffffff0000000000000001 from replica set primary localhost:27018
10:44:15.183 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=12290100, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169140125757}
10:44:15.183 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Setting max set version to 1 from replica set primary localhost:27018
10:44:15.184 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Discovered replica set primary localhost:27018
10:44:15.185 [Test worker] INFO  org.mongodb.driver.cluster - No server chosen by com.mongodb.internal.async.client.ClientSessionHelper$1@d6959b9 from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=localhost:27018, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=5527982, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169133504636}]}. Waiting for 30000 ms before timing out
10:44:15.208 [Thread-12] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:4, serverValue:36}] to localhost:27018
10:44:15.241 [Thread-12] ERROR org.mongodb.driver.connection - Callback onResult call produced an error
java.lang.IllegalStateException: Attempted to decrement the reference count below 0
	at com.mongodb.internal.binding.AbstractReferenceCounted.release(AbstractReferenceCounted.java:39) ~[main/:na]
	at com.mongodb.internal.binding.AsyncClusterBinding$AsyncClusterBindingConnectionSource.release(AsyncClusterBinding.java:135) ~[main/:na]
	at com.mongodb.internal.async.client.ClientSessionBinding$SessionBindingAsyncConnectionSource.release(ClientSessionBinding.java:189) ~[main/:na]
	at com.mongodb.internal.operation.OperationHelper$ReferenceCountedReleasingWrappedCallback.onResult(OperationHelper.java:408) ~[main/:na]
	at com.mongodb.internal.operation.CommandOperationHelper$8.call(CommandOperationHelper.java:413) ~[main/:na]
	at com.mongodb.internal.operation.OperationHelper$7.onResult(OperationHelper.java:613) ~[main/:na]
	at com.mongodb.internal.operation.OperationHelper$7.onResult(OperationHelper.java:610) ~[main/:na]
	at com.mongodb.internal.connection.DefaultServer$1.onResult(DefaultServer.java:112) ~[main/:na]
	at com.mongodb.internal.connection.DefaultServer$1.onResult(DefaultServer.java:103) ~[main/:na]
	at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:48) [main/:na]
	at com.mongodb.internal.connection.DefaultConnectionPool$2.onResult(DefaultConnectionPool.java:217) [main/:na]
	at com.mongodb.internal.connection.DefaultConnectionPool$2.onResult(DefaultConnectionPool.java:207) [main/:na]
	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection$1.onResult(DefaultConnectionPool.java:448) [main/:na]
	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection$1.onResult(DefaultConnectionPool.java:442) [main/:na]
	at com.mongodb.internal.connection.UsageTrackingInternalConnection$1.onResult(UsageTrackingInternalConnection.java:61) [main/:na]
	at com.mongodb.internal.connection.UsageTrackingInternalConnection$1.onResult(UsageTrackingInternalConnection.java:57) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$1$1.onResult(InternalStreamConnection.java:159) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$1$1.onResult(InternalStreamConnection.java:154) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$1.onResult(InternalStreamConnectionInitializer.java:77) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$1.onResult(InternalStreamConnectionInitializer.java:73) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$2.onResult(InternalStreamConnectionInitializer.java:169) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$2.onResult(InternalStreamConnectionInitializer.java:159) [main/:na]
	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:57) [main/:na]
	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:53) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$2$1.onResult(InternalStreamConnection.java:400) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$2$1.onResult(InternalStreamConnection.java:375) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:676) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:643) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:513) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:510) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:220) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:203) [main/:na]
	at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) [na:1.8.0_162]
	at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) [na:1.8.0_162]
	at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297) [na:1.8.0_162]
	at com.mongodb.internal.connection.AsynchronousSocketChannelStream$AsynchronousSocketChannelAdapter.read(AsynchronousSocketChannelStream.java:136) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream.readAsync(AsynchronousChannelStream.java:105) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.readAsync(InternalStreamConnection.java:510) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.access$1000(InternalStreamConnection.java:75) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:633) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:618) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:513) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:510) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:220) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:203) [main/:na]
	at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) [na:1.8.0_162]
	at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) [na:1.8.0_162]
	at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297) [na:1.8.0_162]
	at com.mongodb.internal.connection.AsynchronousSocketChannelStream$AsynchronousSocketChannelAdapter.read(AsynchronousSocketChannelStream.java:136) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream.readAsync(AsynchronousChannelStream.java:105) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.readAsync(InternalStreamConnection.java:510) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.access$1000(InternalStreamConnection.java:75) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$2.onResult(InternalStreamConnection.java:375) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$2.onResult(InternalStreamConnection.java:364) [main/:na]
	at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:48) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:467) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:464) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$1.completed(AsynchronousChannelStream.java:91) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$1.completed(AsynchronousChannelStream.java:85) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$2.completed(AsynchronousChannelStream.java:167) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$2.completed(AsynchronousChannelStream.java:161) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$AsyncWritableByteChannelAdapter$WriteCompletionHandler.completed(AsynchronousChannelStream.java:192) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$AsyncWritableByteChannelAdapter$WriteCompletionHandler.completed(AsynchronousChannelStream.java:183) [main/:na]
	at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) [na:1.8.0_162]
	at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) [na:1.8.0_162]
	at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implWrite(UnixAsynchronousSocketChannelImpl.java:736) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:382) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousSocketChannelImpl.write(AsynchronousSocketChannelImpl.java:399) [na:1.8.0_162]
	at java.nio.channels.AsynchronousSocketChannel.write(AsynchronousSocketChannel.java:577) [na:1.8.0_162]
	at com.mongodb.internal.connection.AsynchronousSocketChannelStream$AsynchronousSocketChannelAdapter.write(AsynchronousSocketChannelStream.java:169) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream$AsyncWritableByteChannelAdapter.write(AsynchronousChannelStream.java:180) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream.pipeOneBuffer(AsynchronousChannelStream.java:161) [main/:na]
	at com.mongodb.internal.connection.AsynchronousChannelStream.writeAsync(AsynchronousChannelStream.java:85) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.writeAsync(InternalStreamConnection.java:464) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendMessageAsync(InternalStreamConnection.java:460) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendCommandMessageAsync(InternalStreamConnection.java:364) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceiveAsync(InternalStreamConnection.java:333) [main/:na]
	at com.mongodb.internal.connection.CommandHelper.executeCommandAsync(CommandHelper.java:52) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.initializeConnectionDescriptionAsync(InternalStreamConnectionInitializer.java:158) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.initializeAsync(InternalStreamConnectionInitializer.java:67) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$1.completed(InternalStreamConnection.java:154) [main/:na]
	at com.mongodb.internal.connection.InternalStreamConnection$1.completed(InternalStreamConnection.java:151) [main/:na]
	at com.mongodb.internal.connection.AsynchronousSocketChannelStream$OpenCompletionHandler.completed(AsynchronousSocketChannelStream.java:107) [main/:na]
	at com.mongodb.internal.connection.AsynchronousSocketChannelStream$OpenCompletionHandler.completed(AsynchronousSocketChannelStream.java:92) [main/:na]
	at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) [na:1.8.0_162]
	at sun.nio.ch.Invoker$2.run(Invoker.java:218) [na:1.8.0_162]
	at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_162]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_162]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]
10:44:15.369 [Thread-12] INFO  org.mongodb.driver.connection - Closed connection [connectionId{localValue:4, serverValue:36}] to localhost:27018 because there was a socket exception raised by this connection.
10:44:15.453 [Test worker] WARN  org.mongodb.driver.connection - Got socket exception on connection [connectionId{localValue:4, serverValue:36}] to localhost:27018. All connections to localhost:27018 will be closed.
10:44:15.455 [Test worker] INFO  org.mongodb.driver.connection - Closed connection [connectionId{localValue:4, serverValue:36}] to localhost:27018 because there was a socket exception raised by this connection.
10:44:15.463 [Test worker] INFO  org.mongodb.driver.cluster - No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=12290100, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169140125757}, ServerDescription{address=localhost:27018, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=5527982, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27018', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Mon Feb 03 10:44:08 UTC 2020, lastUpdateTimeNanos=169133504636}]}. Waiting for 30000 ms before timing out
10:44:15.688 [cluster-ClusterId{value='5e37f97fc485fb071a1dbc72', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Discovered replica set primary localhost:27018
10:44:15.690 [Thread-7] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:5, serverValue:37}] to localhost:27018



 Comments   
Comment by Githook User [ 16/Mar/20 ]

Author:

{'username': 'rozza', 'name': 'Ross Lawley', 'email': 'ross.lawley@gmail.com'}

Message: Ensure getting the description doesn't require the pool to be open.

JAVA-3657 JAVA-3616, JAVA-3647
Branch: 3.12.x
https://github.com/mongodb/mongo-java-driver/commit/a7a3a290364bb546a23d177d61910d1107be13ec

Comment by Githook User [ 13/Mar/20 ]

Author:

{'username': 'rozza', 'name': 'Ross Lawley', 'email': 'ross.lawley@gmail.com'}

Message: Ensure getting the description doesn't require the pool to be open.

JAVA-3657 JAVA-3616, JAVA-3647
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/cedb69c82bd4bd321a2929b4110f574dee5a2881

Comment by Githook User [ 13/Mar/20 ]

Author:

{'username': 'rozza', 'name': 'Ross Lawley', 'email': 'ross.lawley@gmail.com'}

Message: Ensure getting the description doesn't require the pool to be open.

JAVA-3657 JAVA-3616, JAVA-3647
Branch: 4.0.x
https://github.com/mongodb/mongo-java-driver/commit/41ca7ca4f42f0a13daaf7095cadcb4c764171cfa

Comment by Ross Lawley [ 13/Mar/20 ]

This is the sympton of JAVA-3647 / JAVA-3657

Comment by Ross Lawley [ 09/Mar/20 ]

Unfortunately not, I think I'd seen this error in the logs multiple times though.

Comment by Jeffrey Yemin [ 08/Mar/20 ]

ross.lawley do you have a link to the failing test?

Comment by Ross Lawley [ 02/Mar/20 ]

PR: https://github.com/rozza/mongo-java-driver/pull/372

Generated at Thu Feb 08 09:00:01 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.