[2020/01/06 14:31:40.362] com.mongodb.reactivestreams.client.MainTransactionsTest > shouldPassAllOutcomes[errors-client.json: Client side error in command starting transaction] STANDARD_OUT
[2020/01/06 14:31:40.362]     14:31:40.317 [Test worker] INFO  org.mongodb.driver.cluster - Cluster created with settings {hosts=[localhost:27017], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
[2020/01/06 14:31:40.362]     14:31:40.317 [Test worker] INFO  org.mongodb.driver.cluster - No server chosen by com.mongodb.internal.async.client.ClientSessionHelper$1@5b0de350 from cluster description ClusterDescription{type=UNKNOWN, connectionMode=SINGLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out
[2020/01/06 14:31:40.362]     14:31:40.327 [cluster-ClusterId{value='5e1344ccc2ba3b6f93d0598f', description='null'}-localhost:27017] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:624, serverValue:1060}] to localhost:27017
[2020/01/06 14:31:40.362]     14:31:40.327 [cluster-ClusterId{value='5e1344ccc2ba3b6f93d0598f', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=SHARD_ROUTER, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=8, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=392457}
[2020/01/06 14:31:40.362]     14:31:40.351 [async-channel-group-240-handler-executor] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:625, serverValue:1061}] to localhost:27017
[2020/01/06 14:31:40.362]     14:31:40.353 [async-channel-group-240-selector] ERROR org.mongodb.driver.connection.tls - error in selector loop
[2020/01/06 14:31:40.362]     java.nio.channels.CancelledKeyException: null
[2020/01/06 14:31:40.362]     	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73) ~[na:1.8.0_162]
[2020/01/06 14:31:40.362]     	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77) ~[na:1.8.0_162]
[2020/01/06 14:31:40.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup.processPendingInterests(AsynchronousTlsChannelGroup.java:445) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup.loop(AsynchronousTlsChannelGroup.java:418) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup.access$300(AsynchronousTlsChannelGroup.java:67) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup$2.run(AsynchronousTlsChannelGroup.java:188) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.362]     	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     14:31:40.353 [async-channel-group-240-handler-executor] ERROR org.mongodb.driver.client - Callback onResult call produced an error
[2020/01/06 14:31:40.463]     com.mongodb.MongoSecurityException: Exception authenticating MongoCredential{mechanism=SCRAM-SHA-1, userName='bob', source='admin', password=<hidden>, mechanismProperties=<hidden>}
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator.wrapException(SaslAuthenticator.java:173) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator.access$300(SaslAuthenticator.java:40) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator$Continuator.onResult(SaslAuthenticator.java:202) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator$Continuator.onResult(SaslAuthenticator.java:185) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:57) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:53) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$2$1.onResult(InternalStreamConnection.java:400) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$2$1.onResult(InternalStreamConnection.java:375) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:676) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:643) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:513) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$5.completed(InternalStreamConnection.java:510) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:220) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.AsynchronousChannelStream$BasicCompletionHandler.completed(AsynchronousChannelStream.java:203) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannel$3$1.run(AsynchronousTlsChannel.java:151) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]
[2020/01/06 14:31:40.463]     Caused by: java.lang.IllegalStateException: state should be: open
[2020/01/06 14:31:40.463]     	at com.mongodb.assertions.Assertions.isTrue(Assertions.java:70) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.getDescription(DefaultConnectionPool.java:563) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.DefaultConnectionPool$2.onResult(DefaultConnectionPool.java:226) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.DefaultConnectionPool$2.onResult(DefaultConnectionPool.java:207) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection$1.onResult(DefaultConnectionPool.java:451) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection$1.onResult(DefaultConnectionPool.java:442) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.UsageTrackingInternalConnection$1.onResult(UsageTrackingInternalConnection.java:65) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.UsageTrackingInternalConnection$1.onResult(UsageTrackingInternalConnection.java:57) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$1$1.onResult(InternalStreamConnection.java:167) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$1$1.onResult(InternalStreamConnection.java:154) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.completeConnectionDescriptionInitializationAsync(InternalStreamConnectionInitializer.java:192) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.access$100(InternalStreamConnectionInitializer.java:42) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$1$1.onResult(InternalStreamConnectionInitializer.java:87) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer$1$1.onResult(InternalStreamConnectionInitializer.java:81) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator$Continuator.onResult(SaslAuthenticator.java:205) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.SaslAuthenticator$Continuator.onResult(SaslAuthenticator.java:185) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:59) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.CommandHelper$1.onResult(CommandHelper.java:53) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	at com.mongodb.internal.connection.InternalStreamConnection$2$1.onResult(InternalStreamConnection.java:398) [mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:40.463]     	... 13 common frames omitted
[2020/01/06 14:31:40.463]     14:31:40.354 [async-channel-group-240-handler-executor] INFO  org.mongodb.driver.connection - Closed connection [connectionId{localValue:625, serverValue:1061}] to localhost:27017 because there was a socket exception raised by this connection.
[2020/01/06 14:31:50.362]     14:31:50.329 [cluster-ClusterId{value='5e1344ccc2ba3b6f93d0598f', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Exception in monitor thread while connecting to server localhost:27017
[2020/01/06 14:31:50.362]     com.mongodb.MongoInternalException: Unexpected exception
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.InternalStreamConnection.translateWriteException(InternalStreamConnection.java:554) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:432) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendCommandMessage(InternalStreamConnection.java:272) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:256) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.CommandHelper.sendAndReceive(CommandHelper.java:83) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.CommandHelper.executeCommand(CommandHelper.java:38) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:180) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:124) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]
[2020/01/06 14:31:50.362]     Caused by: java.nio.channels.ShutdownChannelGroupException: null
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup.checkTerminated(AsynchronousTlsChannelGroup.java:383) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup.startWrite(AsynchronousTlsChannelGroup.java:344) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannel.write(AsynchronousTlsChannel.java:248) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.AsynchronousChannelStream$AsyncWritableByteChannelAdapter.write(AsynchronousChannelStream.java:180) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.AsynchronousChannelStream.pipeOneBuffer(AsynchronousChannelStream.java:161) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.AsynchronousChannelStream.writeAsync(AsynchronousChannelStream.java:85) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.AsynchronousChannelStream.write(AsynchronousChannelStream.java:119) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:429) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:31:50.362]     	... 7 common frames omitted
[2020/01/06 14:32:00.362]     14:32:00.330 [cluster-ClusterId{value='5e1344ccc2ba3b6f93d0598f', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Exception in monitor thread while connecting to server localhost:27017
[2020/01/06 14:32:00.362]     com.mongodb.MongoException: java.lang.NullPointerException
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:137) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:131) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_162]
[2020/01/06 14:32:00.362]     Caused by: java.lang.NullPointerException: null
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannelGroup$RegisteredSocket.close(AsynchronousTlsChannelGroup.java:124) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.tlschannel.async.AsynchronousTlsChannel.close(AsynchronousTlsChannel.java:414) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.AsynchronousChannelStream.close(AsynchronousChannelStream.java:139) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.close(InternalStreamConnection.java:226) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:431) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendCommandMessage(InternalStreamConnection.java:272) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:256) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.CommandHelper.sendAndReceive(CommandHelper.java:83) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.CommandHelper.executeCommand(CommandHelper.java:33) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.initializeConnectionDescription(InternalStreamConnectionInitializer.java:103) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnectionInitializer.initialize(InternalStreamConnectionInitializer.java:60) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:128) ~[mongodb-driver-core-4.0.0-SNAPSHOT.jar:na]
[2020/01/06 14:32:00.362]     	... 2 common frames omitted
[2020/01/06 15:25:54.420] Command stopped early: context canceled
[2020/01/06 15:25:54.420] Running task-timeout commands.
[2020/01/06 15:25:54.436] Running command 'shell.exec' (step 1 of 1)