enhance find by id query on single node

[Mohamed Elsaka]

Hi,

I am new to MongoDB, i have just deployed it on one of our nodes to give it a try in order to decide porting from MySQL to MongoDB.

But i have a strange performance problem, i found that one of the very basic queries (User.find(id)) is taking around 0.5 sec, i guess i am missing some critical deployment keys.

Our test node has 24 cores with 200 GB of RAM running ubuntu 12.04 LTS and the data size is 500 GB with 1,000,000 records. The application is running on Ruby on Rails framework and i am using mongoid to access mongodb, and we are using passenger with nginx for deployment.

I am using this command "mongod --fork --logpath /var/log/mongodb.log" to run mongodb instance.

Thanks!

[Dwight Merriman]

is the server highly loaded or idle when this is happening?  if the latter this shouldn't happen.

so on User.find( { _id : <value> } ), the _id index (there by default) should make the query fast.

Note that "id" and "_id" are not the same and that "_id" is indexed.  (you could create an index on "id", but that field name might be confusing given the existence of "_id" field)

in the shell you can run an explain plan : 

$ mongo localhost/<yourdbname>

> db.User.find( { _id : _enteravaluehere } ).explain()

you should get back a low nScanned and "btreecursor" or something as the plan if it's using the index.

[Mohamed Elsaka]

Thanks for your reply!

I was running stress testing on my server with apache benchmark tool. I have deployed mongodb on an independent machine that only operates mongodb server.

Here's is what i got from some "htop" and "iotop"

iotop:

Disk Read 30.00 M/S

htop:

VIRT    RES      SHR     MEM  CPU

985GB  8820M   8736M  4.6%  0.04

Here's the output of the last profiled query that takes more than 300 ms

{

"op" : "query",

"ns" : "s_production.users",

"query" : {

"_id" : ObjectId("5379d9af0a3de2efce8e7769")

},

"ntoreturn" : 0,

"ntoskip" : 0,

"nscanned" : 1,

"nscannedObjects" : 1,

"idhack" : true,

"keyUpdates" : 0,

"numYield" : 0,

"lockStats" : {

"timeLockedMicros" : {

"r" : NumberLong(361634),

"w" : NumberLong(0)

},

"timeAcquiringMicros" : {

"r" : NumberLong(1),

"w" : NumberLong(3816)

}

},

"nreturned" : 1,

"responseLength" : 454278,

"millis" : 361,

"execStats" : {

},

"ts" : ISODate("2014-05-25T13:40:21.522Z"),

"client" : "192.168.0.129",

"allUsers" : [ ],

"user" : ""

}

I don't think that my server was overloaded, what do you think about these results?

[Asya Kamsky]

It's a little hard to tell, since turning on profiling changes the
scenario - for example, every query now has to write something to the
system.profile collection.

Can you turn off profiling and instead of looking in system.profile
check the mongod logs - it logs all operations that take more than
100ms by default. Are all the slow operations clustered? Or are they
scattered throughout? Are all of them the same type of queries (by
_id for example?) As Dwight said, the index on "_id" exists always
and the profile output shows that it's being used...

By the way, what version of MongoDB is this?

Asya

> --
> You received this message because you are subscribed to the Google Groups
> "mongodb-user"
> group.
>
> For other MongoDB technical support options, see:
> http://www.mongodb.org/about/support/.
> ---
> You received this message because you are subscribed to the Google Groups
> "mongodb-user" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to mongodb-user...@googlegroups.com.
> To post to this group, send email to mongod...@googlegroups.com.
> Visit this group at http://groups.google.com/group/mongodb-user.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/mongodb-user/baea2d7a-2578-43c7-a1fb-9eaf651deb11%40googlegroups.com.
>
> For more options, visit https://groups.google.com/d/optout.

[Mohamed Elsaka]

Many thanks for your reply, Asya!

Here's my build information

db version v2.6.1

Linux build14.nj1.10gen.cc 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Jan 3 21:39:27 UTC 2014 x86_64 BOOST_LIB_VERSION=1_49

I don't think that writes for profiling would make that impact, i also notices Total Disk Write and it was less than 40 KB/S, which is so far from my server's SSD hard disk maximum write rate.

Regarding the queries, they are clustered, it's the same query with different id each time (i.e. User.find(<id>)).

You received this message because you are subscribed to a topic in the Google Groups "mongodb-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/mongodb-user/4vPWOB0UJZ8/unsubscribe.
To unsubscribe from this group and all its topics, send an email to mongodb-user...@googlegroups.com.

To post to this group, send email to mongod...@googlegroups.com.
Visit this group at http://groups.google.com/group/mongodb-user.

To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CAOe6dJAQAjNgGgWrR2ncRaf%3Ds-cxyU_XfR2vFm%2BaFB6F3YfoxA%40mail.gmail.com.

For more options, visit https://groups.google.com/d/optout.

--

Regards,

Mohamed Elsaka

Software Engineer

Alexandria - Egypt

LinkedIn

[Asya Kamsky]

Can you tell if there is page faulting during the queries?   The only reason I can see for a query on indexed field to take so long would be if the index it needs to read is not (fully) in RAM.

How big are the indexes for the databases, and how much RAM of what the machine has is being used?  You said there are 200 GB of RAM - can you run mongostat for about 20 seconds while running your load test and include it here?  There is really no reason that any single query should take this long unless it's waiting for its "turn" and here the numbers seem to indicate that it was running during that.   

Asya

To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/CAG--_fd6mVqenFpRXz0%2BiH%2Br28f3xUbRpcL80-P8yJyJTibXcw%40mail.gmail.com.