Strange pattern of query response times


#1

I’m seeing a strange pattern of query response times in production. Occasionally (a few times an hour), a bunch of queries happening around the same time will each take just over 10 seconds to execute (e.g., 10.05 seconds). It appears as if something is waiting for exactly 10 seconds before the query actually executes – and the Mongo logs do not show evidence of these queries actually being slow. Has anyone else seen this kind of behavior? (I’m using MongoDB 3.2.8 with WiredTiger on Compose, with oplog enabled.)


#2

Are you using Kadira? Could be useful.


#3

Yes - that’s how I noticed this pattern. Method and publication response times are typically consistent except for these spikes to ~10x their normal times. In the traces, Kadira shows the query fetch times as just over 10 seconds, but Mongo doesn’t log the corresponding queries as slow (which I believe means they are taking under 100ms on the Mongo side).


#4

Might be a process compose is running to manage the database?


#5

That was my thinking initially too, but I’ve spoken to the Compose folks about it extensively and they are convinced that nothing is abnormal about the database.


#6

are you sure oplog tailing is working?

a 10 second delay is exactly the default polling interval if you are not using oplog tailing

Tuning Meteor Mongo Livedata for Scalability (Meteor Blog)
Mongo.Collection#find (API docs)


#7

Yes - Kadira shows that queries are using the oplog. But I am also seeing these 10 second delays on regular fetch calls from methods.