Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-1459

InternalStreamConnection shouldn't log connection initialization failures

XMLWordPrintableJSON

    • Type: Icon: Improvement Improvement
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 3.0.0
    • Affects Version/s: None
    • Component/s: Connection Management
    • Labels:
      None

      Saw this when running the unit tests. Logging should happen higher up. This one in particular is spurious, since it's a normal interrupt situation when the MongoClient is closed.

      Note that this has not been released. This logging was introduced in an unreleased branch, and has been fixed prior to release.

      14:44:28.096 [cluster-11-127.0.0.1:27017] WARN  o.m.driver.ConnectionInitializer - Exception initializing the connection
com.mongodb.MongoInterruptedException: Interrupted acquiring a permit to retrieve an item from the pool 
	at com.mongodb.connection.ConcurrentPool.acquirePermit(ConcurrentPool.java:181) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ConcurrentPool.get(ConcurrentPool.java:121) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ConcurrentPool.get(ConcurrentPool.java:104) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PowerOfTwoBufferPool.getBuffer(PowerOfTwoBufferPool.java:66) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.SocketStream.read(SocketStream.java:64) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.StreamPipeline.receiveResponseBuffers(StreamPipeline.java:253) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.StreamPipeline.receiveMessage(StreamPipeline.java:151) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.receiveMessage(PipelinedConnectionInitializer.java:82) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.receiveReply(CommandHelper.java:73) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.receiveCommandDocument(CommandHelper.java:69) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.executeCommandWithoutCheckingForFailure(CommandHelper.java:42) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.initializeConnectionId(PipelinedConnectionInitializer.java:141) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.initialize(PipelinedConnectionInitializer.java:110) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:92) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.sendMessage(CommandHelper.java:52) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.executeCommand(CommandHelper.java:37) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor.lookupServerDescription(ServerMonitor.java:244) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor.access$400(ServerMonitor.java:63) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor$ServerMonitorRunnable.run(ServerMonitor.java:125) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]
Caused by: java.lang.InterruptedException: null
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1279) ~[na:1.6.0_45]
	at java.util.concurrent.Semaphore.acquire(Semaphore.java:286) ~[na:1.6.0_45]
	at com.mongodb.connection.ConcurrentPool.acquirePermit(ConcurrentPool.java:177) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	... 19 common frames omitted
14:44:28.098 [cluster-11-127.0.0.1:27017] WARN  o.m.driver.InternalStreamConnection - Exception when trying to initialize the connection
com.mongodb.MongoInterruptedException: Interrupted acquiring a permit to retrieve an item from the pool 
	at com.mongodb.connection.ConcurrentPool.acquirePermit(ConcurrentPool.java:181) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ConcurrentPool.get(ConcurrentPool.java:121) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ConcurrentPool.get(ConcurrentPool.java:104) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PowerOfTwoBufferPool.getBuffer(PowerOfTwoBufferPool.java:66) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.SocketStream.read(SocketStream.java:64) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.StreamPipeline.receiveResponseBuffers(StreamPipeline.java:253) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.StreamPipeline.receiveMessage(StreamPipeline.java:151) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.receiveMessage(PipelinedConnectionInitializer.java:82) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.receiveReply(CommandHelper.java:73) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.receiveCommandDocument(CommandHelper.java:69) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.executeCommandWithoutCheckingForFailure(CommandHelper.java:42) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.initializeConnectionId(PipelinedConnectionInitializer.java:141) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.PipelinedConnectionInitializer.initialize(PipelinedConnectionInitializer.java:110) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.InternalStreamConnection.sendMessage(InternalStreamConnection.java:92) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.sendMessage(CommandHelper.java:52) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.CommandHelper.executeCommand(CommandHelper.java:37) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor.lookupServerDescription(ServerMonitor.java:244) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor.access$400(ServerMonitor.java:63) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at com.mongodb.connection.ServerMonitor$ServerMonitorRunnable.run(ServerMonitor.java:125) [mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]
Caused by: java.lang.InterruptedException: null
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1279) ~[na:1.6.0_45]
	at java.util.concurrent.Semaphore.acquire(Semaphore.java:286) ~[na:1.6.0_45]
	at com.mongodb.connection.ConcurrentPool.acquirePermit(ConcurrentPool.java:177) ~[mongo-java-driver-core-3.0.0-SNAPSHOT.jar:na]
	... 19 common frames omitted

            Assignee:
            jeff.yemin@mongodb.com Jeffrey Yemin
            Reporter:
            jeff.yemin@mongodb.com Jeffrey Yemin
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: