[JAVA-2411] MongoDB: java.lang.IllegalStateException: state should be: open Created: 15/Dec/16  Updated: 27/Oct/23  Resolved: 28/Dec/16

Status: Closed
Project: Java Driver
Component/s: None
Affects Version/s: 3.3.0
Fix Version/s: None

Type: Task Priority: Major - P3
Reporter: Evgeny Grin Assignee: Unassigned
Resolution: Works as Designed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File logs_mdb.txt    
Issue Links:
Problem/Incident
causes JAVA-2794 Spring MongoTemplate through exceptio... Closed
Related
related to JAVA-1085 auto retry during failover Closed

 Description   

I have an application that pulls data from one source and then upserts it to MongoDB. Sometimes the pulling process takes a lot of time and when app tries to push a row to MongoDB the following exception is raised probably to the timeout issue:

    com.mongodb.MongoSocketReadException: Prematurely reached end of stream
    	at com.mongodb.connection.SocketStream.read(SocketStream.java:88)
    	at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:492)
    	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:222)
    	at com.mongodb.connection.UsageTrackingInternalConnection.receiveMessage(UsageTrackingInternalConnection.java:105)
    	at com.mongodb.connection.DefaultConnectionPool$PooledConnection.receiveMessage(DefaultConnectionPool.java:438)
    	at com.mongodb.connection.WriteCommandProtocol.receiveMessage(WriteCommandProtocol.java:262)
    	at com.mongodb.connection.WriteCommandProtocol.execute(WriteCommandProtocol.java:104)
    	at com.mongodb.connection.UpdateCommandProtocol.execute(UpdateCommandProtocol.java:64)
    	at com.mongodb.connection.UpdateCommandProtocol.execute(UpdateCommandProtocol.java:37)
    	at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:168)
    	at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:289)
    	at com.mongodb.connection.DefaultServerConnection.updateCommand(DefaultServerConnection.java:143)
    	at com.mongodb.operation.MixedBulkWriteOperation$Run$3.executeWriteCommandProtocol(MixedBulkWriteOperation.java:481)
    	at com.mongodb.operation.MixedBulkWriteOperation$Run$RunExecutor.execute(MixedBulkWriteOperation.java:647)
    	at com.mongodb.operation.MixedBulkWriteOperation$Run.execute(MixedBulkWriteOperation.java:400)
    	at com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:180)
    	at com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:169)
    	at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:232)
    	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:223)
    	at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:169)
    	at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:75)
    	at com.mongodb.Mongo.execute(Mongo.java:827)
    	at com.mongodb.Mongo$2.execute(Mongo.java:810)
    	at com.mongodb.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:515)
    	at com.mongodb.MongoCollectionImpl.update(MongoCollectionImpl.java:508)
    	at com.mongodb.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:355)
    	at com.test.db.mongoDB.RetryingMongoCollection.updateOne(RetryingMongoCollection.java:909)

There is a wrapper for MongoCollection class that for each MongoException and now for java.lang.IllegalStateException thrown

    @Override
    public UpdateResult updateOne(Bson filter, Bson update,
    		UpdateOptions updateOptions) {
    	UpdateResult retVal = null;
    	final ExceptionHelper ex = new ExceptionHelper(CAConstants.RETRIES, ErrorType.ERROR, true);
    	boolean isDone = false;
    	while (!isDone) {
    		try {
    			retVal = proxied.updateOne(filter, update, updateOptions);
    			isDone = true;
    		} catch (final MongoException | IllegalStateException e) {
    			ex.logIfZero("Failed to launch MongoDB operation", e);
    			if (ex.lastTry()) {
    				isDone = true;
    				Log.error("Failed to launch MongoDB operation.", e);
    			} else {
    				Log.error("[MDB] Going to update mongo instance due to exception", e);
    				db = MongoDBFactory.getUpdatedMongoDBInstance();
    				setCollection();
    			}
    		}
    	}
    	return retVal;
    }

tries to reload MongoClient:

    		if ( mongoClient != null ) {
    			try {
    				mongoClient.close();
    			} catch (Exception e) {
    				Log.error("Mongo client throws exception while closing connection", e);
    			}
    ...
    		mongoClient = new MongoClient(servers, Arrays.asList(credential), 
    				new MongoClientOptions.Builder()
    					.requiredReplicaSetName(REPLICASET_NAME)
    					.connectTimeout(0)
    					.connectionsPerHost(CONNECTION_PER_HOST)
    					.cursorFinalizerEnabled(false)
    					.build());
    		
    		db = mongoClient.getDatabase(database);

However, when the mongoClient is updated after "com.mongodb.MongoSocketReadException: Prematurely reached end of stream" it fails with:

    java.lang.IllegalStateException: state should be: open
    	at com.mongodb.assertions.Assertions.isTrue(Assertions.java:70)
    	at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:82)
    	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:75)
    	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:71)
    	at com.mongodb.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:68)
    	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:221)
    	at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:169)
    	at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:75)
    	at com.mongodb.Mongo.execute(Mongo.java:827)
    	at com.mongodb.Mongo$2.execute(Mongo.java:810)
    	at com.mongodb.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:515)
    	at com.mongodb.MongoCollectionImpl.update(MongoCollectionImpl.java:508)
    	at com.mongodb.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:355)
    	at com.test.db.mongoDB.RetryingMongoCollection.updateOne(RetryingMongoCollection.java:909)

and continues failing all the time...

I use mongoDB ver 3.2.9
MongoDB Java client 3.3.0

Per request, the RetryingMongoCollection.java starts with:

public class RetryingMongoCollection<T> implements MongoCollection<T> {
    private MongoCollection<T> proxied;
    private MongoDatabase db;
    private final String collectionName;
    
    public RetryingMongoCollection(MongoDatabase db, final String collectionName) {
        this.collectionName = collectionName;
        this.db = db;
        setCollection();
    }
    
    @SuppressWarnings("unchecked")
	private void setCollection() {
    	this.proxied = (MongoCollection<T>) db.getCollection(collectionName);
    }
...

Then we override each and every com.mongodb.client.MongoCollection<T> method the same way as we do with updateOne method.



 Comments   
Comment by Jeffrey Yemin [ 19/Dec/16 ]

Hi Evgeny,

Currently the driver never retries an operation, leaving it to the application to determine whether to do so. JAVA-1085 is currently tracking this feature request.

Regards,
Jeff

Comment by Evgeny Grin [ 18/Dec/16 ]

Hi Jeff, in addition to my last question: I get today an exception "com.mongodb.MongoNotPrimaryException: The server is not the primary and did not execute the operation". As I mentioned previously, I have provided all three replica set members to Java client. Should not Java client to treat this issue by itself? Is there any reason that this error message came up to my handling?

Comment by Evgeny Grin [ 16/Dec/16 ]

The question that i have than is - if the driver knows how to treat replica set failover why we catch this exception? Should not it be treated internally in the driver code?

Comment by Jeffrey Yemin [ 16/Dec/16 ]

Yes, you're right about the "Prematurely reached end of stream". It can certainly happen during a replica set failover.

The driver handles replica set failover automatically. A single-threaded application should expect to receive a single failure for any operation that's in progress when the failover occurs. Subsequent operations should block until the driver discovers the new primary. The gory details are described in two specifications that we've published : Server Discovery and Monitoring and Server Selection.

Comment by Evgeny Grin [ 16/Dec/16 ]

Furthermore, today I guess I figured out the reason for the initial issue - "Prematurely reached end of stream".
I figured out that this issue occures exactly at the same time when MongoDB replica set members interchange in their roles: PRIMARY & SECONDARY.
While it does not resolve the issue I reported it brings me to another question: whether java driver has to figure out the situation when replica set member it has open a socket to turns to be a SECONDARY instead of PRIMARY and the new socket to the PRIMARY member has to be created by itself and reconnect automatically to the new PRIMARY member?

Comment by Evgeny Grin [ 16/Dec/16 ]

Hi Jeff,

The issue I posted occurred while running in one thread.

Actually, I already did that and the log now looks like as in the attached file (logs_mdb.txt)

As you can see it always reconnect. I am afraid that it can cause to a huge number of opened connections from both sides: server & client.

I agree regarding the last point. That's the reason that we catch only MongoDB exceptions. In case it is network or system issue the re-applying won't happen.

Comment by Jeffrey Yemin [ 15/Dec/16 ]

Are you using an instance of RetryingMongoCollection concurrently from multiple threads? If so, that would explain the second exception, which the MongoClient throws when an application attempts to use it after it's been closed. Basically there is a race condition in which one thread closes a MongoClient instance that is still in use by other threads.

I think the simplest solution here is to simply not close the MongoClient when there is an exception. The MongoClient class is designed to recover from any sporadic failure to connect to the MongoDB cluster to which it is connected, so applications are free to simply retry an operation using the same MongoClient instance.

One other note of caution: not all updates are idempotent. It's not safe in the general case to simply retry all updates until thy succeeds, as it may end up being applied more than once. Consider for example an update that uses the $inc operator. The application could write the update command to the socket, the server receives it and applies it, and connectivity is disrupted before the application reads the response. If the application simply retries that update, the increment will end up being applied twice.

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