[JAVA-1459] InternalStreamConnection shouldn't log connection initialization failures Created: 19/Sep/14  Updated: 12/Feb/15  Resolved: 24/Sep/14

Status: Closed
Project: Java Driver
Component/s: Connection Management
Affects Version/s: None
Fix Version/s: 3.0.0

Type: Improvement Priority: Major - P3
Reporter: Jeffrey Yemin Assignee: Jeffrey Yemin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

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



 Comments   
Comment by Githook User [ 30/Jan/15 ]

Author:

{u'username': u'jyemin', u'name': u'Jeff Yemin', u'email': u'jeff.yemin@10gen.com'}

Message: Removed logging of initialization failure, as that should be logged higher up.
Also changed the name of the logger to be the module name rather than the class name, as it is elsewhere.

JAVA-1459
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/5d25cb3135431ccb58da18b55d4be86284d50f02

Comment by Githook User [ 24/Sep/14 ]

Author:

{u'username': u'jyemin', u'name': u'Jeff Yemin', u'email': u'jeff.yemin@10gen.com'}

Message: Removed logging of initialization failure, as that should be logged higher up.
Also changed the name of the logger to be the module name rather than the class name, as it is elsewhere.

JAVA-1459
Branch: 3.0.x
https://github.com/mongodb/mongo-java-driver/commit/5d25cb3135431ccb58da18b55d4be86284d50f02

Generated at Thu Feb 08 08:54:40 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.