[JAVA-2091] Exception: Interrupted acquiring a permit to retrieve an item from the pool Created: 19/Jan/16  Updated: 21/Jan/16  Resolved: 21/Jan/16

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

Type: Bug Priority: Major - P3
Reporter: Justin Knight Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu, connecting to single instance of Mongo DB 3.0.6 on localhost



 Description   

We recently upgraded from a older version of the MongoDB driver to 3.2 and are see multiple exceptions being thrown.

Our application runs OK for a day or so but then we're seeing this exception being thrown frequently...

Error message
com.mongodb.MongoInterruptedException: Interrupted acquiring a permit to retrieve an item from the pool
 
Sample stack trace
…ngodb.internal.connection.ConcurrentPool.acquirePermit (ConcurrentPool.java:186)
 
     com.mongodb.internal.connection.ConcurrentPool.get (ConcurrentPool.java:126)
 
…b.connection.DefaultConnectionPool.getPooledConnection (DefaultConnectionPool.java:250)
 
       com.mongodb.connection.DefaultConnectionPool.get (DefaultConnectionPool.java:91)
 
       com.mongodb.connection.DefaultConnectionPool.get (DefaultConnectionPool.java:80)
com.mongodb.connection.DefaultConnectionPool.get
 
     com.mongodb.connection.DefaultServer.getConnection (DefaultServer.java:72)
 
…erBinding$ClusterBindingConnectionSource.getConnection (ClusterBinding.java:86)
 
…mongodb.operation.OperationHelper.withConnectionSource (OperationHelper.java:228)
 
   com.mongodb.operation.OperationHelper.withConnection (OperationHelper.java:221)
 
  com.mongodb.operation.MixedBulkWriteOperation.execute (MixedBulkWriteOperation.java:168)
 
  com.mongodb.operation.MixedBulkWriteOperation.execute (MixedBulkWriteOperation.java:74)
 
                              com.mongodb.Mongo.execute (Mongo.java:782)
 
                            com.mongodb.Mongo$2.execute (Mongo.java:765)
 
….mongodb.MongoCollectionImpl.executeSingleWriteRequest (MongoCollectionImpl.java:515)
 
             com.mongodb.MongoCollectionImpl.replaceOne (MongoCollectionImpl.java:344)
 
 com.mapov.availability.AvailabilityCache.cacheResponse (AvailabilityCache.java:62)
 
 com.mapov.availability.AvailabilityCache.cacheResponse (AvailabilityCache.java:45)
 
….availability.AvailabilityRequestHandler.cacheResponse (AvailabilityRequestHandler.java:146)
 
…apov.availability.AvailabilityRequestHandler.sendError (AvailabilityRequestHandler.java:204)
 
     com.mapov.availability.agoda.AgodaAvailability.run (AgodaAvailability.java:93)
 
      java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1142)
 
     java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:617)
 
                                   java.lang.Thread.run (Thread.java:745)
 
 
caused by java.lang.InterruptedException
…locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos (AbstractQueuedSynchronizer.java:1326)
 
              java.util.concurrent.Semaphore.tryAcquire (Semaphore.java:409)
 
…ngodb.internal.connection.ConcurrentPool.acquirePermit (ConcurrentPool.java:180)
 
     com.mongodb.internal.connection.ConcurrentPool.get (ConcurrentPool.java:126)
 
…b.connection.DefaultConnectionPool.getPooledConnection (DefaultConnectionPool.java:250)
 
       com.mongodb.connection.DefaultConnectionPool.get (DefaultConnectionPool.java:91)
 
       com.mongodb.connection.DefaultConnectionPool.get (DefaultConnectionPool.java:80)
 
     com.mongodb.connection.DefaultServer.getConnection (DefaultServer.java:72)
 
…erBinding$ClusterBindingConnectionSource.getConnection (ClusterBinding.java:86)
 
…mongodb.operation.OperationHelper.withConnectionSource (OperationHelper.java:228)
 
   com.mongodb.operation.OperationHelper.withConnection (OperationHelper.java:221)
 
  com.mongodb.operation.MixedBulkWriteOperation.execute (MixedBulkWriteOperation.java:168)
 
  com.mongodb.operation.MixedBulkWriteOperation.execute (MixedBulkWriteOperation.java:74)
 
                              com.mongodb.Mongo.execute (Mongo.java:782)
 
                            com.mongodb.Mongo$2.execute (Mongo.java:765)
 
….mongodb.MongoCollectionImpl.executeSingleWriteRequest (MongoCollectionImpl.java:515)
 
             com.mongodb.MongoCollectionImpl.replaceOne (MongoCollectionImpl.java:344)
 
 com.mapov.availability.AvailabilityCache.cacheResponse (AvailabilityCache.java:62)
 
 com.mapov.availability.AvailabilityCache.cacheResponse (AvailabilityCache.java:45)
 
….availability.AvailabilityRequestHandler.cacheResponse (AvailabilityRequestHandler.java:146)
 
…apov.availability.AvailabilityRequestHandler.sendError (AvailabilityRequestHandler.java:204)
 
     com.mapov.availability.agoda.AgodaAvailability.run (AgodaAvailability.java:93)
 
      java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1142)
 
     java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:617)
 
                                   java.lang.Thread.run (Thread.java:745)

We have a single MongoClient instance:

package com.mapov.availability;
 
import com.mongodb.MongoClient;
import com.mongodb.client.MongoDatabase;
 
/**
 *
 * @author Justin
 */
public class MongoConnection {
  private static MongoClient mongoClient = null;
  
  private MongoConnection() {
    // Private constructor
  }
  
  public static MongoDatabase getMapovDB() {
    if( mongoClient == null) {
      mongoClient = new MongoClient();
    }
    return mongoClient.getDatabase("mapov");
  }
}

This is the cache code, called from multiple threads:

package com.mapov.availability;
 
import com.mapov.util.Util;
import com.mongodb.BasicDBObject;
import com.mongodb.client.MongoCollection;
import com.mongodb.client.MongoDatabase;
import com.mongodb.client.model.Filters;
import com.mongodb.client.model.UpdateOptions;
import java.util.logging.Logger;
import org.bson.Document;
import org.bson.conversions.Bson;
import org.joda.time.DateTime;
import static com.mongodb.client.model.Filters.*;
import static com.mongodb.client.model.Sorts.*;
 
/**
 *
 * @author Justin
 */
public class AvailabilityCache {
 
  private static final Logger logger = Logger.getLogger(AvailabilityCache.class.getName());
  private static final int cacheExpirySeconds = 3600; // Default cache time is 1 hour
  private final MongoCollection<Document> cacheCollection;
 
  public AvailabilityCache() {
    MongoDatabase mapovDB = MongoConnection.getMapovDB();
    this.cacheCollection = mapovDB.getCollection("availability");
  }
 
  private BasicDBObject buildKey(AvailabilityRequest request, AvailabilityResponse response) {
    BasicDBObject key = new BasicDBObject("startDate", request.startDate);
    key.append("endDate", request.endDate);
    key.append("locale", request.locale);
    key.append("rooms", Util.implode(request.rooms, ","));
    key.append("children", Util.implode(request.children, ","));
    key.append("cpID", response.cpID);
    key.append("providerPropertyID", response.providerPropertyID);
    key.append("currency", request.currencyCode);
 
    return key;
  }
 
  public void cacheResponse(AvailabilityRequest request, AvailabilityResponse response) {
    cacheResponse(request, response, cacheExpirySeconds);
  }
 
  public void cacheResponse(AvailabilityRequest request, AvailabilityResponse response, int cacheExpirySeconds) {
    BasicDBObject key = buildKey(request, response);
 
    Document doc = new Document();
    doc.append("_id", key);
    doc.append("rate", (int)response.rate*100);
    doc.append("deepLink", response.deepLink);
    doc.append("availableRooms", response.availableRooms);
    doc.append("error", response.error);
    doc.append("errorMsg", response.errorMsg);
    DateTime expiry = DateTime.now().plusSeconds(cacheExpirySeconds);
    doc.append("expireAt", expiry.toDate());
    UpdateOptions uo = new UpdateOptions();
    uo.upsert(true);
    cacheCollection.replaceOne(Filters.eq("_id", key),doc, uo);//Upserts
  }
 
  public boolean checkCache(AvailabilityRequest request, AvailabilityResponse response) {
    boolean found = false;
    
    BasicDBObject key = buildKey(request, response);
    Bson query = eq("_id", key);
    Bson orderBy = descending("expireAt");
 
    Document result = (Document)cacheCollection.find(query).sort(orderBy).first();
    if( result!=null) {
      response.rate = (Integer)result.get("rate")/100;
      response.deepLink = (String)result.get("deepLink");
      response.error = (Integer)result.get("error");
      response.errorMsg = (String)result.get("errorMsg");
      if( result.containsKey("availableRooms")) {
        response.availableRooms = (Integer)result.get("availableRooms");
      }
      found = true;
      //logger.log(Level.INFO, "Cache match: {0}", response);
    }
 
    return found;
  }
}



 Comments   
Comment by Jeffrey Yemin [ 21/Jan/16 ]

Thanks for reporting the resolution of this issue. I'm closing it as Works as Designed.

Comment by Justin Knight [ 21/Jan/16 ]

On further investigation it seems the exception is being thrown because the thread has already been interrupted when the mongo call is made. In these circumstances it seems reasonable for Java driver to throw this exception.

Comment by Justin Knight [ 21/Jan/16 ]

ExecutorService#shutdownNow is called on the threads after a 10 second timeout. Normally the threads take less than a second to run.

Is it possible that mongo connections are leaking somehow? That could cause the mongo operations to take longer than the timeout causing the exceptions to start firing.

Comment by Jeffrey Yemin [ 20/Jan/16 ]

Looking more closely at the stack trace, I see that the driver code is being executed via an executor service. My current hypothesis is that application code is calling the java.util.concurrent.ExecutorService#shutdownNow method on an ExecutorService instance that is generating this stack trace. Please check to see if that is a possibility.

Comment by Justin Knight [ 20/Jan/16 ]

Hi Jeff,

  • We were previously on the 3.0.0-beta3 version of the driver.
  • The application is standalone running on JVM version 1.8.0_60
Comment by Jeffrey Yemin [ 19/Jan/16 ]

A few questions:

  • What version of the driver did you upgrade from?
  • Is your application running inside of a container, e.g. Tomcat, JBoss, etc, or is it a standalone application?
Generated at Thu Feb 08 08:56:17 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.