Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

I see the following error in my mongodb river setup - Exception while looping in cursor #351

Open
dharshanr opened this issue Oct 24, 2014 · 5 comments

Comments

@dharshanr
Copy link

.mongodirector.com}]
[2014-10-24 18:09:20,178][INFO ][river.mongodb ] Server: SG-Test-3788.servers.mongodirector.com - 27017
[2014-10-24 18:09:20,178][INFO ][river.mongodb ] Server: SG-Test-3789.servers.mongodirector.com - 27017
[2014-10-24 18:09:20,178][TRACE][river.mongodb ] mongoOptionsSettings: {secondary_read_preference=false}
[2014-10-24 18:09:20,178][INFO ][org.elasticsearch.river.mongodb.MongoDBRiver] Starting river account_10
[2014-10-24 18:09:20,182][DEBUG][river.mongodb.util ] setRiverStatus called with account_10 - RUNNING
[2014-10-24 18:09:20,186][DEBUG][org.elasticsearch.river.mongodb.MongoDBRiver] Using mongodb server(s): host [SG-Test-3788.servers.mongodirector.com], port [27017]
[2014-10-24 18:09:20,186][DEBUG][org.elasticsearch.river.mongodb.MongoDBRiver] Using mongodb server(s): host [SG-Test-3789.servers.mongodirector.com], port [27017]
[2014-10-24 18:09:20,186][INFO ][org.elasticsearch.river.mongodb.MongoDBRiver] MongoDB River Plugin - version[2.0.1] - hash[445c35a] - time[2014-07-30T14:08:26Z]
[2014-10-24 18:09:20,186][INFO ][org.elasticsearch.river.mongodb.MongoDBRiver] starting mongodb stream. options: secondaryreadpreference [false], drop_collection [false], include_c
ollection [], throttlesize [5000], gridfs [false], filter [null], db [account_10], collection [contacts], script [null], indexing to [account_10]/[contacts]
[2014-10-24 18:09:20,188][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] MongoAdminUser: admin - authenticated: false
[2014-10-24 18:09:20,188][INFO ][org.elasticsearch.river.mongodb.MongoDBRiver] Authenticate admin with admin
[2014-10-24 18:09:20,201][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] authenticateCommand: { "serverUsed" : "SG-Test-3788.servers.mongodirector.com:27017" , "dbname" : "ad
min" , "user" : "admin" , "ok" : 1.0} - isAuthenticated: true
[2014-10-24 18:09:20,201][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] Found admin database
[2014-10-24 18:09:20,201][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] About to execute: { "serverStatus" : 1 , "asserts" : 0 , "backgroundFlushing" : 0 , "connections" : 0
, "cursors" : 0 , "dur" : 0 , "extra_info" : 0 , "globalLock" : 0 , "indexCounters" : 0 , "locks" : 0 , "metrics" : 0 , "network" : 0 , "opcounters" : 0 , "opcountersRepl" : 0 , "
recordStats" : 0 , "repl" : 0}
[2014-10-24 18:09:20,202][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] Command executed return : { "serverUsed" : "SG-Test-3788.servers.mongodirector.com:27017" , "host" :
"ip-10-11-170-101" , "version" : "2.6.4" , "process" : "mongod" , "pid" : 3656 , "uptime" : 72472.0 , "uptimeMillis" : 72472062 , "uptimeEstimate" : 71528.0 , "localTime" : { "$dat
e" : "2014-10-24T18:09:20.205Z"} , "ok" : 1.0}
[2014-10-24 18:09:20,202][INFO ][org.elasticsearch.river.mongodb.MongoDBRiver] MongoDB version - 2.6.4
[2014-10-24 18:09:20,202][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] serverStatus: { "serverUsed" : "SG-Test-3788.servers.mongodirector.com:27017" , "host" : "ip-10-11-17
0-101" , "version" : "2.6.4" , "process" : "mongod" , "pid" : 3656 , "uptime" : 72472.0 , "uptimeMillis" : 72472062 , "uptimeEstimate" : 71528.0 , "localTime" : { "$date" : "2014-1
0-24T18:09:20.205Z"} , "ok" : 1.0}
[2014-10-24 18:09:20,202][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] process: mongod
[2014-10-24 18:09:20,203][TRACE][org.elasticsearch.river.mongodb.MongoDBRiver] Not mongos
[2014-10-24 18:09:20,204][INFO ][org.elasticsearch.river.mongodb.Slurper] Authenticate admin with admin
[2014-10-24 18:09:20,217][INFO ][org.elasticsearch.river.mongodb.Slurper] MongoDBRiver is beginning initial import of account_10.contacts
[2014-10-24 18:09:20,219][INFO ][org.elasticsearch.river.mongodb.Slurper] Collection contacts - count: 1
[2014-10-24 18:09:20,219][INFO ][org.elasticsearch.river.mongodb.Slurper] Number documents indexed: 1
[2014-10-24 18:09:20,230][DEBUG][org.elasticsearch.river.mongodb.MongoDBRiver] setLastTimestamp [account_10] [account_10.contacts] [Timestamp.BSON(ts={ "$ts" : 1414174160 , "$inc"
: 57})]
[2014-10-24 18:09:20,658][WARN ][org.elasticsearch.river.mongodb.Slurper] Exception while looping in cursor
com.mongodb.MongoInterruptedException: Interrupted acquiring a permit to retrieve an item from the pool
at com.mongodb.ConcurrentPool.acquirePermit(ConcurrentPool.java:172)
at com.mongodb.ConcurrentPool.get(ConcurrentPool.java:112)
at com.mongodb.PooledConnectionProvider.get(PooledConnectionProvider.java:75)
at com.mongodb.DefaultServer.getConnection(DefaultServer.java:61)
at com.mongodb.BaseCluster$WrappedServer.getConnection(BaseCluster.java:248)
at com.mongodb.DBTCPConnector$MyPort.getConnection(DBTCPConnector.java:503)
at com.mongodb.DBTCPConnector$MyPort.get(DBTCPConnector.java:434)
at com.mongodb.DBTCPConnector.innerCall(DBTCPConnector.java:286)
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:271)
at com.mongodb.DBTCPConnector.call(DBTCPConnector.java:237)
at com.mongodb.QueryResultIterator.getMore(QueryResultIterator.java:137)
at com.mongodb.QueryResultIterator.hasNext(QueryResultIterator.java:127)
at com.mongodb.DBCursor._hasNext(DBCursor.java:551)
at com.mongodb.DBCursor.hasNext(DBCursor.java:571)
at org.elasticsearch.river.mongodb.Slurper.run(Slurper.java:125)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1325)
at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:414)
at com.mongodb.ConcurrentPool.acquirePermit(ConcurrentPool.java:166)
... 15 more

@ankon
Copy link
Contributor

ankon commented Nov 5, 2014

At this point the slurper will have stopped, and no longer process incoming data.

Some questions: Does this happen reproducibly? How many rivers are you using?

@linusyong
Copy link

I had this problem, resolved by slowing down the slurper:

    "index": {
        "name": "users",
        "type": "user",
        "throttle_size": 10,
        "bulk_size": 3,
        "bulk": {
                "actions": 25,
                "concurrent_requests": 3
        }
    }

@derEremit
Copy link

Hi, @linusyong
I'm having a similar problem, but as these "advanced" options have no more explanation than "you can set this option" i really don't know what you did to slow down the slurper?

@EthanLeo-Kafka
Copy link

I got a similar problem, it occurred in JUnit Test. So, How to resolve that?

@yitao
Copy link

yitao commented Oct 27, 2016

@windrunners
if you use asynchronous code in your junit test,then may be show this exception.
you should let main thread sleep long time to avoid this.
you can try this ,like:
//other thread running code
try {
Thread.sleep(10000000);
} catch (InterruptedException e) {
e.printStackTrace();
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants