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

Refactor JOB_PROCESS_WHERE_QUERY to get an optimized query plan #869

Merged

Conversation

@mfred488
Copy link
Contributor

mfred488 commented Oct 11, 2019

This pull request is a simple "refactoring" of the job-pulling query performed by agenda, that yieldsbetter results when there are lots of "expired" jobs in database. As far as I can see, there's no functional impact.

Context:
I recently ended up in a situation with a lot of "expired" jobs in database, i.e. jobs with nextRunAt< current date.
In that situation, I saw mongod CPU consumption climbing pretty high, and after checking mongo logs, I saw that the regular "job pulling" request performed by agenda scanned a lot of index keys.

I managed to reproduce this on my computer. I first created 100k "expired Jobs":

var yesterday = Date.now() - 86400000;
var bulk = db.agendaJobs.initializeUnorderedBulkOp();
for (var i = 0; i < 100000; i++) {
  bulk.insert({"name" : "CAMPAIGN_JOB", "data" : {}, "type" : "normal", "priority" : 0, "nextRunAt" : new Date(yesterday + _rand()*10000), "lastModifiedBy" : null });
}
bulk.execute();

Then checked the explain plan of the job pulling request done by agenda:

> db.agendaJobs.explain("executionStats").findAndModify({ "findAndModify" : "agendaJobs", "query" : { "$or" : [ { "name" : "CAMPAIGN_JOB", "lockedAt" : null, "nextRunAt" : { "$lte" : ISODate("2019-10-11T12:24:29.460Z") }, "disabled" : { "$ne" : true } }, { "name" : "CAMPAIGN_JOB", "lockedAt" : { "$exists" : false }, "nextRunAt" : { "$lte" : ISODate("2019-10-11T12:24:29.460Z") }, "disabled" : { "$ne" : true } }, { "name" : "CAMPAIGN_JOB", "lockedAt" : { "$lte" : ISODate("2019-10-11T12:14:28.460Z") }, "disabled" : { "$ne" : true } } ] }, "sort" : { "nextRunAt" : 1, "priority" : -1 }, "new" : true, "remove" : false, "upsert" : false, "update" : { "$set" : { "lockedAt" : ISODate("2019-10-11T12:24:28.460Z") } } })
{
  "queryPlanner": ...,
  "executionStats": {
		"executionSuccess" : true,
		"nReturned" : 1,
		"executionTimeMillis" : 50,
		"totalKeysExamined" : 9991,
		"totalDocsExamined" : 4,
		"executionStages": ...
  }
}

So 10k index keys were examined :(

One of my colleague played with the query, and found out that with a simple "refactoring" of the request, we got a much better query plan:

> db.agendaJobs.explain("executionStats").findAndModify({ "findAndModify" : "agendaJobs", "query" : { "$and" : [ { "name" : "CAMPAIGN_JOB", "disabled" : { "$ne" : true } }, { "$or" : [ { "lockedAt" : { "$eq" : null }, "nextRunAt" : { "$lte" : ISODate("2019-10-11T12:37:54.917Z") } }, { "lockedAt" : { "$lte" : ISODate("2019-10-11T12:27:53.917Z") } } ] } ] }, "sort" : { "nextRunAt" : 1, "priority" : -1 }, "new" : true, "remove" : false, "upsert" : false, "update" : { "$set" : { "lockedAt" : ISODate("2019-10-11T12:37:53.917Z") } } })
{
	"queryPlanner" : ...
	"executionStats" : {
		"executionSuccess" : true,
		"nReturned" : 1,
		"executionTimeMillis" : 2,
		"totalKeysExamined" : 109,
		"totalDocsExamined" : 109,
		"executionStages" : ...
	}
}

Only 100~ keys examined!

disabled: {$ne: true}
}, {
name: jobName,
lockedAt: {$exists: false},

This comment has been minimized.

Copy link
@simison

simison Nov 24, 2019

Member

Do you know if this lockedAt: {$exists: false} should be one of the options in $or?

I'm just a little confused because I'm seeing only lockedAt: {$eq: null} and lockedAt: {$lte: lockDeadline} from the old query.

This comment has been minimized.

Copy link
@koresar

koresar Nov 24, 2019

AFAIK (from the top of my head) your can check both existence and null equality with "$eq: null". Whereas the "$exists: false" checks the existence only.

But I don't trust my memory too much. 🙂 So, please double check.

In other words, the PR is okay IMO.

This comment has been minimized.

Copy link
@simison

simison Nov 24, 2019

Member

Sounds good! Thanks.

@simison

This comment has been minimized.

Copy link
Member

simison commented Nov 24, 2019

Thank you! I appreciate elaborate testing instructions.

Just a small questi on before we could merge this; #869 (review)

Pardon that it took so long to get back to this. :-)

@simison simison merged commit 3e07e8e into agenda:master Nov 24, 2019
2 checks passed
2 checks passed
continuous-integration/travis-ci/pr The Travis CI build passed
Details
security/snyk - package.json (agenda) No manifest changes detected
@mfred488 mfred488 deleted the mfred488:job-process-where-query-optimization branch Nov 25, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.