Spring Data MongoDB Slow MongoTemplate.find() Performance

Question

I'm having performance issues when querying ~12,000 user documents, indexed by 1 column, (companyId), no other filter. The whole collection only has ~27000. It took me about 12 seconds to get the ~12000 rows of data...

I tried running explain for this query: db.instoreMember.find({companyId:"5b6be3e2096abd567974f924"}).explain();

result follows:

{
    "queryPlanner" : {
        "plannerVersion" : 1,
        "namespace" : "production.instoreMember",
        "indexFilterSet" : false,
        "parsedQuery" : {
            "companyId" : {
                "$eq" : "5b6be3e2096abd567974f924"
            }
        },
        "winningPlan" : {
            "stage" : "FETCH",
            "inputStage" : {
                "stage" : "IXSCAN",
                "keyPattern" : {
                    "companyId" : 1,
                    "name" : 1,
                    "phoneNumber" : 1
                },
                "indexName" : "companyId_1_name_1_phoneNumber_1",
                "isMultiKey" : false,
                "multiKeyPaths" : {
                    "companyId" : [ ],
                    "name" : [ ],
                    "phoneNumber" : [ ]
                },
                "isUnique" : true,
                "isSparse" : false,
                "isPartial" : false,
                "indexVersion" : 2,
                "direction" : "forward",
                "indexBounds" : {
                    "companyId" : [
                        "[\"5b6be3e2096abd567974f924\", \"5b6be3e2096abd567974f924\"]"
                    ],
                    "name" : [
                        "[MinKey, MaxKey]"
                    ],
                    "phoneNumber" : [
                        "[MinKey, MaxKey]"
                    ]
                }
            }
        },
        "rejectedPlans" : [
            {
                "stage" : "FETCH",
                "inputStage" : {
                    "stage" : "IXSCAN",
                    "keyPattern" : {
                        "companyId" : 1
                    },
                    "indexName" : "companyId_1",
                    "isMultiKey" : false,
                    "multiKeyPaths" : {
                        "companyId" : [ ]
                    },
                    "isUnique" : false,
                    "isSparse" : false,
                    "isPartial" : false,
                    "indexVersion" : 2,
                    "direction" : "forward",
                    "indexBounds" : {
                        "companyId" : [
                            "[\"5b6be3e2096abd567974f924\", \"5b6be3e2096abd567974f924\"]"
                        ]
                    }
                }
            }
        ]
    },
    "serverInfo" : {

    },
    "ok" : 1
}

It seems that it is actually using the indexed companyId field, and if i do the search directly via mongodb shell, it's very fast: only 1~2 seconds.

But via Spring MongoDB Data - MongoTemplate:

final Query query = new Query().addCriteria(Criteria.where("companyId").is(adminCompanyId));
final List<InstoreMember> listOfInstoreMembers = mongoTemplate.find(query, InstoreMember.class);

This becomes very slow ~10-12seconds. (How i measure is that I put a break point at the find statement, let it step through to next line, which took about ~10-12seconds)

I've added the DEBUG line for mongodb spring bootstrap and here is the logged output of the find statement :

2018-08-14 23:53:34.493 DEBUG 22733 --- [bio-8080-exec-2] o.s.data.mongodb.core.MongoTemplate      : 
find using query: { "companyId" : "58fa36dd31d103038e64b061"} fields: null for class: class fn.model.InstoreMember in collection: instoreMember

Version of spring-data-mongodb i use:

compile ("org.springframework.data:spring-data-mongodb:1.10.7.RELEASE")

Could you please post some sample code and documents? With the amount of information given it's virtually impossible to guess what the problem is... — dnickless, Aug 14 '18 at 09:03
If you are using Spring Boot, add this in application.properties and post the result logging.level.org.springframework.data.mongodb.core.MongoTemplate=DEBUG — Marco, Aug 14 '18 at 09:53
Check this out for logging all queries: https://stackoverflow.com/a/29849568/6440033 — dnickless, Aug 14 '18 at 09:54
How did you measure the 12s? The query itself cannot possibly be this slow unless you have a really slow spinning disk or some super slow network... — dnickless, Aug 14 '18 at 10:00
i just put a debug statement at the mongoTemplate.find, run it, wait out ~12secs and it then it would stop at the next line.. — user1955934, Aug 14 '18 at 16:39
I think my query is pretty basic i dont understand why it differs so much versus running the query using mongodb command line client.. — user1955934, Aug 14 '18 at 16:41
Marco I added the log results from adding that debug line in application.properties it seems that the query is correct, but it's still very slow. I'm so stuck — user1955934, Aug 14 '18 at 16:56

score 4 · Answer 1 · answered May 16 '19 at 01:11

I had this problem.

The slow part is mapping Document to Java object. Mongo template doesn't map at the codec level so it goes bson->Document->POJO. If you use just the mongo driver with the POJO codec that will go bson->pojo and remove the template mapping layer overhead.

Also, if you have old data and have moved packages, this will also break their mapping layer and make it super slow as it falls back to reflection.

score 1 · Answer 2 · answered Aug 14 '18 at 09:58

1

How do i see the raw query that is actually being executed by spring mongodb data?

If the query is taking 12 seconds to load, you actually have time to run db.currentOp to see what is taking so long. The output will contain 'command' field that you can use to see what the DB has been tasked with.

answered Aug 14 '18 at 09:58

tonysepia

3,340
3
27
45

{ "inprog" : [ ], "ok" : 1, "operationTime" : Timestamp(1534265282, 6) } It gives me the above when it's taking its time on the mongoTemplate.find() step – user1955934 Aug 14 '18 at 16:48
@user1955934 I think this may indicate that once it's 'taking its time' it's not querying the DB. Can you step into the statement to isolate further what causes the wait? – tonysepia Aug 15 '18 at 09:49
but that is MongoTemplate's code. This is some very basic .find query i wouldn't expect the problem be with the library...although it's possible..? – user1955934 Aug 15 '18 at 16:34
@user1955934 step through their code if you can, as it sounds like you want to learn about what's happening inside – tonysepia Aug 15 '18 at 16:55
it's a different case if my query is special/unique, i will probably try to find out what's going on with the library. But this is truly, almost the hello world of the library... i mean come on I'm sure thousands of ppl use this library, it certainly wouldn't fail at the most basic find query? I might miss something or i'm using it the wrong way, i hope someone can point that something out – user1955934 Aug 16 '18 at 09:16

score 0 · Answer 3 · answered Aug 14 '18 at 16:53

0

To see the raw query being executed you can update the log level of the mongodb driver dependency to debug level. This should log the query to your log file.

answered Aug 14 '18 at 16:53

Rishabh Agarwal

1,988
1
16
33

You can also check the git repo of the mongodb driver https://github.com/spring-projects/spring-data-mongodb . Considering you use: org.springframework.data spring-data-mongodb – Rishabh Agarwal Aug 14 '18 at 16:55

Spring Data MongoDB Slow MongoTemplate.find() Performance

3 Answers3

Linked