Neeld help fixing slow queries on Mongo

Discussion:

Panabee

2013-05-26 09:38:56 UTC

Hi there,

We're extremely frustrated and could use some advice. Mongo acts sluggish
when we attempt to return the games associated with a player. In our player
document, we store an array of game IDs.

The query returns an array of game documents based on these game IDs. We
were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.

* Mongo log entries: https://gist.github.com/panabee/621e64fd3fa289dccc5b &
https://gist.github.com/panabee/944b607c0c53b928c0f9
* Query with explain: https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042

Can anyone help? We have tried everything but cannot improve performance.
Our database isn't even very large as the app isn't in full-scale
deployment. If we can't find a solution, we may need to rewrite everything
in MySQL, which we have more experience with, but obviously this is an
unattractive option.

Thanks!
--
--
You received this message because you are subscribed to the Google
Groups "mongodb-user" group.
To post to this group, send email to mongodb-user-/***@public.gmane.org
To unsubscribe from this group, send email to
mongodb-user+unsubscribe-/***@public.gmane.org
See also the IRC channel -- freenode.net#mongodb

---
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+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/***@public.gmane.org
For more options, visit https://groups.google.com/groups/opt_out.

Asya Kamsky

2013-05-26 19:39:33 UTC

Permalink

Can you provide some information about the server that mongod is running on?
In particular: how much RAM does it have, what sort of disk is the /data
directory on, and is there anything else running on this machine?
Is the server in MMS by any chance? If not, could you run 'mongostat'
command for about 1-2 minutes and paste the output into a gist?

I suspect I know what might be the limiting factor(s) but without knowing
more about the server I would be guessing.

Asya

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts sluggish
when we attempt to return the games associated with a player. In our player
document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs. We
were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
* Mongo log entries: https://gist.github.com/panabee/621e64fd3fa289dccc5b
& https://gist.github.com/panabee/944b607c0c53b928c0f9
* Query with explain: https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve performance.
Our database isn't even very large as the app isn't in full-scale
deployment. If we can't find a solution, we may need to rewrite everything
in MySQL, which we have more experience with, but obviously this is an
unattractive option.
Thanks!

--
--
You received this message because you are subscribed to the Google
Groups "mongodb-user" group.
To post to this group, send email to mongodb-user-/***@public.gmane.org
To unsubscribe from this group, send email to
mongodb-user+unsubscribe-/***@public.gmane.org
See also the IRC channel -- freenode.net#mongodb

---
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+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/***@public.gmane.org
For more options, visit https://groups.google.com/groups/opt_out.

Panabee

2013-05-26 19:50:04 UTC

Permalink

Our machine is running on a VPS with 30 other nodes. Specs (using the 2560
plan, which offers 5 GB RAM total):
http://railsplayground.com/plans-products/vps/. The hosting provider
analyzed our VPS during peak usage and said I/O and CPU utilization were
extremely healthy. We asked about a dedicated server, but given the light
load (not yet in full deployment), he didn't think a dedicated server would
make a difference. Mongostat output:
https://gist.github.com/panabee/f0729abc16eafef989f4.

Thanks for your help! You don't understand how much we would love you if
you could provide clues on how to fix this. Thanks again!

Post by Asya Kamsky
Can you provide some information about the server that mongod is running on?
In particular: how much RAM does it have, what sort of disk is the /data
directory on, and is there anything else running on this machine?
Is the server in MMS by any chance? If not, could you run 'mongostat'
command for about 1-2 minutes and paste the output into a gist?
I suspect I know what might be the limiting factor(s) but without knowing
more about the server I would be guessing.
Asya

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts sluggish
when we attempt to return the games associated with a player. In our player
document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs. We
were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
* Mongo log entries: https://gist.github.com/panabee/621e64fd3fa289dccc5b
& https://gist.github.com/panabee/944b607c0c53b928c0f9
https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve performance.
Our database isn't even very large as the app isn't in full-scale
deployment. If we can't find a solution, we may need to rewrite everything
in MySQL, which we have more experience with, but obviously this is an
unattractive option.
Thanks!

Asya Kamsky

2013-05-26 20:05:38 UTC

Permalink

Is this mongostat while some queries were running? And during that time
period some of the queries were slow?
It helps to correlate the mongostat output with slow queries from the logs.
Would you check the logs from 23:42:58UTC till 23:47:24?

Asya

Post by Panabee
Our machine is running on a VPS with 30 other nodes. Specs (using the 2560
http://railsplayground.com/plans-products/vps/. The hosting provider
analyzed our VPS during peak usage and said I/O and CPU utilization were
extremely healthy. We asked about a dedicated server, but given the light
load (not yet in full deployment), he didn't think a dedicated server would
https://gist.github.com/panabee/f0729abc16eafef989f4.
Thanks for your help! You don't understand how much we would love you if
you could provide clues on how to fix this. Thanks again!

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts
sluggish when we attempt to return the games associated with a player. In
our player document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs. We
were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
https://gist.github.com/panabee/621e64fd3fa289dccc5b &
https://gist.github.com/panabee/944b607c0c53b928c0f9
https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve
performance. Our database isn't even very large as the app isn't in
full-scale deployment. If we can't find a solution, we may need to rewrite
everything in MySQL, which we have more experience with, but obviously this
is an unattractive option.
Thanks!

Panabee

2013-05-28 08:17:45 UTC

Permalink

hi asya,

i forgot to answer these questions:

1) yes, some queries were running. none of the queries were slow.

2) we pulled all the mongo log entries from 23:40 - 23:49. they are now at
the bottom under the mongostat output:
https://gist.github.com/panabee/f0729abc16eafef989f4.

does this or the last email help shed insight on the problem?

thanks!

Post by Asya Kamsky
Is this mongostat while some queries were running? And during that time
period some of the queries were slow?
It helps to correlate the mongostat output with slow queries from the logs.
Would you check the logs from 23:42:58UTC till 23:47:24?
Asya

Post by Panabee
Our machine is running on a VPS with 30 other nodes. Specs (using the
http://railsplayground.com/plans-products/vps/. The hosting provider
analyzed our VPS during peak usage and said I/O and CPU utilization were
extremely healthy. We asked about a dedicated server, but given the light
load (not yet in full deployment), he didn't think a dedicated server would
https://gist.github.com/panabee/f0729abc16eafef989f4.
Thanks for your help! You don't understand how much we would love you if
you could provide clues on how to fix this. Thanks again!

Post by Asya Kamsky
Can you provide some information about the server that mongod is running on?
In particular: how much RAM does it have, what sort of disk is the /data
directory on, and is there anything else running on this machine?
Is the server in MMS by any chance? If not, could you run 'mongostat'
command for about 1-2 minutes and paste the output into a gist?
I suspect I know what might be the limiting factor(s) but without
knowing more about the server I would be guessing.
Asya

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts
sluggish when we attempt to return the games associated with a player. In
our player document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs.
We were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
https://gist.github.com/panabee/621e64fd3fa289dccc5b &
https://gist.github.com/panabee/944b607c0c53b928c0f9
https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve
performance. Our database isn't even very large as the app isn't in
full-scale deployment. If we can't find a solution, we may need to rewrite
everything in MySQL, which we have more experience with, but obviously this
is an unattractive option.
Thanks!

Asya Kamsky

2013-05-26 21:48:34 UTC

Permalink

So even before getting more information back, looking over the data you
provided I can see that there are three separate problems (at least -
possibly more).

1. Your queries against the player collection are slow because there is no
effective index to use to satisfy the query (and the sort):

Typical example:

{ $query: { last_login_at: { $gte: new Date(1369554064848) },
ios_token: { $ne: null },
play_random: true,
_id: { $nin: [ ObjectId('51a14fce4552d015ea000215'),
ObjectId('51a14fce4552d015ea000215') ] },
username_downcase: { $ne: "you" } },
$orderby: { _id: -1 } }
ntoreturn:50 ntoskip:0 nscanned:11911 scanAndOrder:1 nreturned:17

You can see that to return 17 (all that matched) 11911 documents had to be
scanned! Plus the results had to be sorted in RAM rather than read off in
order.
Why is this? Well, the index being used is ... hey, what indexes are
available?

"_id_" : 1283632,
"username_downcase" : 1610672,
"ios_token" : 5159056

These are not very helpful! Every condition you provide is very
unselective (user not you, ios_token not null, _id not in {list of two})...
So one index is used to "narrow down" 43 thousand players down to 12
thousand players, the rest have to be examined to find the 17 that satisfy
the query (and by the way, since you are asking for limit 50 it will
examine the whole collection while it's looking for 50 to return).

Answer to this would be to have a compound index that can be more
effectively used to immediately find the matching records (and read them in
order).

2. You have queries against players which use the $where clause - that is
always going to be extremely slow as it has to spawn a javascript thread to
evaluate the condition:
players query: { $where: "this.puzzle_packs.length > 60" } ntoreturn:50
nscanned:18034 nreturned:50 1480ms
You can see that 18034 records had to be scanned with no index help
possible! You should figure out a different way to get the matching
records here - either keep count of the number of puzzle_packs in the
corresponding document (and index it) or use another technique to see if
length of an array is > 60.

3. Queries from games collection are always by _id so they always use the
optimal index. How come are they sometimes slow:

Tue May 21 11:40:07 [conn12813] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 6 locks(micros) r:4546736 nreturned:35 reslen:96272 2581ms

Tue May 21 11:40:07 [conn12815] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 1 locks(micros) r:2498343 nreturned:35 reslen:96272 1466ms

Tue May 21 11:40:09 [conn12815] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 2 locks(micros) r:3972995 nreturned:35 reslen:96272 2349ms

Tue May 21 11:40:09 [conn12813] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 2 locks(micros) r:4038191 nreturned:35 reslen:96272 2382ms

Here note the field numYields. All of these queries found 35 documents to
return of 69 provided "keys" but they had to wait for some of those
documents to be swapped in from disk. How do we know that? Because we
yield a lock when we are waiting for something (i.e. we only hold the lock
while we are actively doing something). What I find particularly strange
is that these four queries are actually the same query issued by two
different connections twice each within two seconds of each other - and the
query took longer than that to complete. Is it possible you have
something in the application code that might cause repeated queries of the
same results when they don't return "fast enough"?

The main issue here though is page faulting - in short mongostat example
you sent it appears that your application is using very little RAM and yet
we see page faulting happening. Why is it not using more of the available
RAM? Possibility one is there is less RAM available than is supposed to
be. Possibility two is high disk readahead setting making use of RAM very
inefficient. Possibility 3 ... well, who knows - we'd have to have
answers to these questions first... Hope this is a good place for you to
start - physical resource sizing/utilization is hard to measure (though you
can run iostat yourself rather than trusting your hosting provider (they
might consider something healthy that's not well suited for your needs).

Asya

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts
sluggish when we attempt to return the games associated with a player. In
our player document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs. We
were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
https://gist.github.com/panabee/621e64fd3fa289dccc5b &
https://gist.github.com/panabee/944b607c0c53b928c0f9
https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve
performance. Our database isn't even very large as the app isn't in
full-scale deployment. If we can't find a solution, we may need to rewrite
everything in MySQL, which we have more experience with, but obviously this
is an unattractive option.
Thanks!

Panabee

2013-05-27 09:56:50 UTC

Permalink

Thanks for all your help, Asya. We really appreciate it. First, sorry for
the confusion, but we fixed the players query by creating another smaller
collection to query against. We were doing some unnecessary things like
sorting, as you pointed out. The challenge now is to accelerate the game
queries, which are causing performance issues.

1) Yes, players can cause repeat queries, but these generally don't happen
unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

2) Our RA value is 256. We already know this is too high and are moving to
a dedicated server where we can reduce the RA to 16. Do you recommend
another value based on our stats output
(https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

3) How can we confirm how much RAM is available to Mongo?

4) How can you tell there are pagefaults based on Mongostat? When we look
at the faults column, it says 0 all the way through. We would like to learn
so we know how to monitor Mongo ourselves.

5) Since we're already using the _id index against the games query, but is
there anything else we can do to optimize the query? Could fragmentation in
the WoppleGames collection be causing issues?

Thanks again for all your help!

Post by Asya Kamsky
So even before getting more information back, looking over the data you
provided I can see that there are three separate problems (at least -
possibly more).
1. Your queries against the player collection are slow because there is no
{ $query: { last_login_at: { $gte: new Date(1369554064848) },
ios_token: { $ne: null },
play_random: true,
_id: { $nin: [ ObjectId('51a14fce4552d015ea000215'),
ObjectId('51a14fce4552d015ea000215') ] },
username_downcase: { $ne: "you" } },
$orderby: { _id: -1 } }
ntoreturn:50 ntoskip:0 nscanned:11911 scanAndOrder:1 nreturned:17
You can see that to return 17 (all that matched) 11911 documents had to be
scanned! Plus the results had to be sorted in RAM rather than read off in
order.
Why is this? Well, the index being used is ... hey, what indexes are
available?
"_id_" : 1283632,
"username_downcase" : 1610672,
"ios_token" : 5159056
These are not very helpful! Every condition you provide is very
unselective (user not you, ios_token not null, _id not in {list of two})...
So one index is used to "narrow down" 43 thousand players down to 12
thousand players, the rest have to be examined to find the 17 that satisfy
the query (and by the way, since you are asking for limit 50 it will
examine the whole collection while it's looking for 50 to return).
Answer to this would be to have a compound index that can be more
effectively used to immediately find the matching records (and read them in
order).
2. You have queries against players which use the $where clause - that is
always going to be extremely slow as it has to spawn a javascript thread to
players query: { $where: "this.puzzle_packs.length > 60" } ntoreturn:50
nscanned:18034 nreturned:50 1480ms
You can see that 18034 records had to be scanned with no index help
possible! You should figure out a different way to get the matching
records here - either keep count of the number of puzzle_packs in the
corresponding document (and index it) or use another technique to see if
length of an array is > 60.
3. Queries from games collection are always by _id so they always use the
Tue May 21 11:40:07 [conn12813] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 6 locks(micros) r:4546736 nreturned:35 reslen:96272 2581ms
Tue May 21 11:40:07 [conn12815] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 1 locks(micros) r:2498343 nreturned:35 reslen:96272 1466ms
Tue May 21 11:40:09 [conn12815] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 2 locks(micros) r:3972995 nreturned:35 reslen:96272 2349ms
Tue May 21 11:40:09 [conn12813] query p.games query: { _id: { $in: [ ObjectId('5164e3864552d04228001558'), ... ObjectId('5199dfee4552d062b100018e') ] } } ntoreturn:0 ntoskip:0 nscanned:69 keyUpdates:0 numYields: 2 locks(micros) r:4038191 nreturned:35 reslen:96272 2382ms
Here note the field numYields. All of these queries found 35 documents
to return of 69 provided "keys" but they had to wait for some of those
documents to be swapped in from disk. How do we know that? Because we
yield a lock when we are waiting for something (i.e. we only hold the lock
while we are actively doing something). What I find particularly strange
is that these four queries are actually the same query issued by two
different connections twice each within two seconds of each other - and the
query took longer than that to complete. Is it possible you have
something in the application code that might cause repeated queries of the
same results when they don't return "fast enough"?
The main issue here though is page faulting - in short mongostat example
you sent it appears that your application is using very little RAM and yet
we see page faulting happening. Why is it not using more of the available
RAM? Possibility one is there is less RAM available than is supposed to
be. Possibility two is high disk readahead setting making use of RAM very
inefficient. Possibility 3 ... well, who knows - we'd have to have
answers to these questions first... Hope this is a good place for you to
start - physical resource sizing/utilization is hard to measure (though you
can run iostat yourself rather than trusting your hosting provider (they
might consider something healthy that's not well suited for your needs).
Asya

Post by Asya Kamsky
Can you provide some information about the server that mongod is running on?
In particular: how much RAM does it have, what sort of disk is the /data
directory on, and is there anything else running on this machine?
Is the server in MMS by any chance? If not, could you run 'mongostat'
command for about 1-2 minutes and paste the output into a gist?
I suspect I know what might be the limiting factor(s) but without
knowing more about the server I would be guessing.
Asya

Post by Panabee
Hi there,
We're extremely frustrated and could use some advice. Mongo acts
sluggish when we attempt to return the games associated with a player. In
our player document, we store an array of game IDs.
The query returns an array of game documents based on these game IDs.
We were advised that fragmentation would not pose an issue in the player
collection as long as we only stored game IDs and didn't let the array
expand too much (i.e., cap around 1000 entries). We included output from
stats in case you're curious about fragmentation.
https://gist.github.com/panabee/621e64fd3fa289dccc5b &
https://gist.github.com/panabee/944b607c0c53b928c0f9
https://gist.github.com/panabee/479816fc457d00ec09d7
* Model: https://gist.github.com/panabee/908b9c024663a6e8dfa4
* Mongo stats: https://gist.github.com/panabee/1ece342e8b5b95040ac3
* Indices: https://gist.github.com/panabee/97a93649566f36b0e042
Can anyone help? We have tried everything but cannot improve
performance. Our database isn't even very large as the app isn't in
full-scale deployment. If we can't find a solution, we may need to rewrite
everything in MySQL, which we have more experience with, but obviously this
is an unattractive option.
Thanks!

Asya Kamsky

2013-05-28 17:17:49 UTC

Permalink

I'm glad you were able to fix your player collection queries, those
definitely had a lot of room for optimization.

Post by Panabee
1) Yes, players can cause repeat queries, but these generally don't happen
unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

Given the long running queries output, that's doesn't quite seem to match.
I would re-check your application logic and timeouts.

Post by Panabee
2) Our RA value is 256. We already know this is too high and are moving to
a dedicated server where we can reduce the RA to 16. Do you recommend
another value based on our stats output (
https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

16 or 32 should be okay. Don't forget to restart mongod processes for new
readahead to take effect. One caution though - your overall average object
size for that database is much higher than average object size of these two
collections we've been talking about. If I were you I would take a look at
the other 10-12 collections and see how they are being used and if they me
impacting anything on your overall system performance.

Post by Panabee
3) How can we confirm how much RAM is available to Mongo?

Check how much RAM is on the machine, check how much other applications are
using. You have 4.11GB memory mapped so if you are accessing all of your
data on a system that has 5GB of RAM however, you said your plan was 2650
and that's only half that and less than what your total data/indexes total
up to... Still, that only explains slower queries when numYields is
non-zero.

4) How can you tell there are pagefaults based on Mongostat? When we look

Post by Panabee
at the faults column, it says 0 all the way through. We would like to learn
so we know how to monitor Mongo ourselves.

If you look at the column "faults" in mongostat - it's frequently 0 but you
can see (at 23:44:33 for instance) it jumps to 29. But mainly I can see
you have indexes on this DB that are almost 40MB plus all your data in just
those two collections is 2.3GB - so *all* of your data definitely cannot
fit in RAM so unless you are querying a very small subset of it you will
get some page faulting. What's not clear is how much your other "bad"
queries (that had to scan a lot of data to find records they needed) were
contributing to your performance problem.

Post by Panabee
5) Since we're already using the _id index against the games query, but is
there anything else we can do to optimize the query? Could fragmentation in
the WoppleGames collection be causing issues?

First, can you re-do the "explain" on that query? I noticed that the one
where you included .explain() output you are not querying correctly. x is
a document with an array of games so your query syntax should be db.wopple_games.find(
{_id : {$in : x.games} }).explain() (you can see that nothing matched so
that tipped me off to check what x actually is above).

Another output that might help would be if you ran `db.serverStatus({workingSet:1})`
at mongo shell prompt.

And lastly, if nothing else sheds any light on the matter, then I would
suggest turning on for a while profiling on this database and then
examining system.profile collection to see what exactly is going on with
these queries. I might even suggest lowering the threshold
(db.setProfilingLevel(2, 50) - just don't forget to set it back when you've
collected enough to analyze to be db.setProfilingLevel(0, 100) ).

Asya
P.S. installing MMS agent would allow much better long term analysis of
performance, etc. https://mms.10gen.com/help/monitoring/install/
--
--
You received this message because you are subscribed to the Google
Groups "mongodb-user" group.
To post to this group, send email to mongodb-user-/***@public.gmane.org
To unsubscribe from this group, send email to
mongodb-user+unsubscribe-/***@public.gmane.org
See also the IRC channel -- freenode.net#mongodb

---
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+unsubscribe-/JYPxA39Uh5TLH3MbocFF+G/***@public.gmane.org
For more options, visit https://groups.google.com/groups/opt_out.

Panabee

2013-05-28 19:40:24 UTC

Permalink

thanks again, asya! you're awesome. we'll enable profiling and share the
output later today. regarding your questions:

1) here's the workingSet output:
https://gist.github.com/panabee/57fe41417fed645ee035

2) the hardware provider said we essentially have 5 GB of RAM (though only
2.5 GB are guaranteed).

3) how do we know if the other collections are impacting performance?

4) new explain output: https://gist.github.com/panabee/479816fc457d00ec09d7

Post by Asya Kamsky
I'm glad you were able to fix your player collection queries, those
definitely had a lot of room for optimization.

Post by Panabee
1) Yes, players can cause repeat queries, but these generally don't
happen unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

Given the long running queries output, that's doesn't quite seem to match.
I would re-check your application logic and timeouts.

Post by Panabee
2) Our RA value is 256. We already know this is too high and are moving
to a dedicated server where we can reduce the RA to 16. Do you recommend
another value based on our stats output (
https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

16 or 32 should be okay. Don't forget to restart mongod processes for
new readahead to take effect. One caution though - your overall average
object size for that database is much higher than average object size of
these two collections we've been talking about. If I were you I would take
a look at the other 10-12 collections and see how they are being used and
if they me impacting anything on your overall system performance.

Post by Panabee
3) How can we confirm how much RAM is available to Mongo?

Check how much RAM is on the machine, check how much other applications
are using. You have 4.11GB memory mapped so if you are accessing all of
your data on a system that has 5GB of RAM however, you said your plan was
2650 and that's only half that and less than what your total data/indexes
total up to... Still, that only explains slower queries when numYields is
non-zero.
4) How can you tell there are pagefaults based on Mongostat? When we look

Post by Panabee
at the faults column, it says 0 all the way through. We would like to learn
so we know how to monitor Mongo ourselves.

If you look at the column "faults" in mongostat - it's frequently 0 but
you can see (at 23:44:33 for instance) it jumps to 29. But mainly I can
see you have indexes on this DB that are almost 40MB plus all your data in
just those two collections is 2.3GB - so *all* of your data definitely
cannot fit in RAM so unless you are querying a very small subset of it you
will get some page faulting. What's not clear is how much your other "bad"
queries (that had to scan a lot of data to find records they needed) were
contributing to your performance problem.

Post by Panabee
5) Since we're already using the _id index against the games query, but
is there anything else we can do to optimize the query? Could fragmentation
in the WoppleGames collection be causing issues?

Asya Kamsky

2013-05-28 20:10:57 UTC

Permalink

A few quick comments.

You are running 2.2.0 which is old and had bugs - if you want to stay on
2.2 branch at least upgrade to 2.2.4 but I would recommend just going to
the latest (2.4.3).

Your explain shows reasonable 45 ms for this query (use index to look up
almost 1000 documents of which half are found in the index and need to be
fetched from the collection). If you run it a few times in a row do you
get better than 45ms time?

You have three databases in this mongod - two of them are labeled
"-development" - I usually would not mix development and production systems
as any random thing can be happening in development and you wouldn't want
it to impact your production database.

I would try to isolate the production database from your own development
DBs as well as other processes. Without seeing profiling it may be hard
to guess more, but again, I'm pretty certain that most of your slowness is
related to data not fitting in RAM. By the way, working set size estimate
is new for 2.4 so given you are running 2.2 I wasn't able to see relevant
data about your working set size...

Asya

Post by Panabee
thanks again, asya! you're awesome. we'll enable profiling and share the
https://gist.github.com/panabee/57fe41417fed645ee035
2) the hardware provider said we essentially have 5 GB of RAM (though only
2.5 GB are guaranteed).
3) how do we know if the other collections are impacting performance?
https://gist.github.com/panabee/479816fc457d00ec09d7

Post by Asya Kamsky
I'm glad you were able to fix your player collection queries, those
definitely had a lot of room for optimization.

Post by Panabee
1) Yes, players can cause repeat queries, but these generally don't
happen unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

Given the long running queries output, that's doesn't quite seem to
match. I would re-check your application logic and timeouts.

Post by Panabee
2) Our RA value is 256. We already know this is too high and are moving
to a dedicated server where we can reduce the RA to 16. Do you recommend
another value based on our stats output (
https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

16 or 32 should be okay. Don't forget to restart mongod processes for
new readahead to take effect. One caution though - your overall average
object size for that database is much higher than average object size of
these two collections we've been talking about. If I were you I would take
a look at the other 10-12 collections and see how they are being used and
if they me impacting anything on your overall system performance.

Post by Panabee
3) How can we confirm how much RAM is available to Mongo?

Check how much RAM is on the machine, check how much other applications
are using. You have 4.11GB memory mapped so if you are accessing all of
your data on a system that has 5GB of RAM however, you said your plan was
2650 and that's only half that and less than what your total data/indexes
total up to... Still, that only explains slower queries when numYields is
non-zero.
4) How can you tell there are pagefaults based on Mongostat? When we look

Post by Panabee
at the faults column, it says 0 all the way through. We would like to learn
so we know how to monitor Mongo ourselves.

If you look at the column "faults" in mongostat - it's frequently 0 but
you can see (at 23:44:33 for instance) it jumps to 29. But mainly I can
see you have indexes on this DB that are almost 40MB plus all your data in
just those two collections is 2.3GB - so *all* of your data definitely
cannot fit in RAM so unless you are querying a very small subset of it you
will get some page faulting. What's not clear is how much your other "bad"
queries (that had to scan a lot of data to find records they needed) were
contributing to your performance problem.

Post by Panabee
5) Since we're already using the _id index against the games query, but
is there anything else we can do to optimize the query? Could fragmentation
in the WoppleGames collection be causing issues?

Panabee

2013-05-28 20:49:34 UTC

Permalink

we ran the explain query a few more times, and we got 3 ms a few times and
a few around 45 ms. does this mean anything?

Post by Asya Kamsky
A few quick comments.
You are running 2.2.0 which is old and had bugs - if you want to stay on
2.2 branch at least upgrade to 2.2.4 but I would recommend just going to
the latest (2.4.3).
Your explain shows reasonable 45 ms for this query (use index to look up
almost 1000 documents of which half are found in the index and need to be
fetched from the collection). If you run it a few times in a row do you
get better than 45ms time?
You have three databases in this mongod - two of them are labeled
"-development" - I usually would not mix development and production systems
as any random thing can be happening in development and you wouldn't want
it to impact your production database.
I would try to isolate the production database from your own development
DBs as well as other processes. Without seeing profiling it may be hard
to guess more, but again, I'm pretty certain that most of your slowness is
related to data not fitting in RAM. By the way, working set size estimate
is new for 2.4 so given you are running 2.2 I wasn't able to see relevant
data about your working set size...
Asya

Post by Panabee
thanks again, asya! you're awesome. we'll enable profiling and share the
https://gist.github.com/panabee/57fe41417fed645ee035
2) the hardware provider said we essentially have 5 GB of RAM (though
only 2.5 GB are guaranteed).
3) how do we know if the other collections are impacting performance?
https://gist.github.com/panabee/479816fc457d00ec09d7

Post by Asya Kamsky
I'm glad you were able to fix your player collection queries, those
definitely had a lot of room for optimization.

Post by Panabee
1) Yes, players can cause repeat queries, but these generally don't
happen unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

Given the long running queries output, that's doesn't quite seem to
match. I would re-check your application logic and timeouts.

Post by Panabee
2) Our RA value is 256. We already know this is too high and are moving
to a dedicated server where we can reduce the RA to 16. Do you recommend
another value based on our stats output (
https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

16 or 32 should be okay. Don't forget to restart mongod processes for
new readahead to take effect. One caution though - your overall average
object size for that database is much higher than average object size of
these two collections we've been talking about. If I were you I would take
a look at the other 10-12 collections and see how they are being used and
if they me impacting anything on your overall system performance.

Post by Panabee
3) How can we confirm how much RAM is available to Mongo?

Check how much RAM is on the machine, check how much other applications
are using. You have 4.11GB memory mapped so if you are accessing all of
your data on a system that has 5GB of RAM however, you said your plan was
2650 and that's only half that and less than what your total data/indexes
total up to... Still, that only explains slower queries when numYields is
non-zero.
4) How can you tell there are pagefaults based on Mongostat? When we

Post by Panabee
look at the faults column, it says 0 all the way through. We would like to
learn so we know how to monitor Mongo ourselves.

If you look at the column "faults" in mongostat - it's frequently 0 but
you can see (at 23:44:33 for instance) it jumps to 29. But mainly I can
see you have indexes on this DB that are almost 40MB plus all your data in
just those two collections is 2.3GB - so *all* of your data definitely
cannot fit in RAM so unless you are querying a very small subset of it you
will get some page faulting. What's not clear is how much your other "bad"
queries (that had to scan a lot of data to find records they needed) were
contributing to your performance problem.

Post by Panabee
5) Since we're already using the _id index against the games query, but
is there anything else we can do to optimize the query? Could fragmentation
in the WoppleGames collection be causing issues?

Asya Kamsky

2013-05-28 22:48:33 UTC

Permalink

This means that your working set is bigger than available RAM - first time
is slower (45ms) because some of the documents may not be in RAM and
subsequent queries are fast because everything is in RAM.
*If* you get slow queries occasionally immediately after a fast one
(meaning that the data wouldn't have had time to get swapped out of RAM)
then most likely your system is overloaded in some other way (I would check
other things running on it - you can start with top I suppose).

Asya

Post by Panabee
we ran the explain query a few more times, and we got 3 ms a few times and
a few around 45 ms. does this mean anything?

Post by Panabee
thanks again, asya! you're awesome. we'll enable profiling and share the
https://gist.github.com/panabee/57fe41417fed645ee035
2) the hardware provider said we essentially have 5 GB of RAM (though
only 2.5 GB are guaranteed).
3) how do we know if the other collections are impacting performance?
https://gist.github.com/panabee/479816fc457d00ec09d7

Post by Asya Kamsky
I'm glad you were able to fix your player collection queries, those
definitely had a lot of room for optimization.

Post by Panabee
1) Yes, players can cause repeat queries, but these generally don't
happen unless a query takes 20+ seconds to finish. It is also possible that
sometimes players accidentally cause a second query to execute moments
after initiating the first query.

Given the long running queries output, that's doesn't quite seem to
match. I would re-check your application logic and timeouts.

Post by Panabee
2) Our RA value is 256. We already know this is too high and are
moving to a dedicated server where we can reduce the RA to 16. Do you
recommend another value based on our stats output (
https://gist.github.com/panabee/1ece342e8b5b95040ac3)?

16 or 32 should be okay. Don't forget to restart mongod processes for
new readahead to take effect. One caution though - your overall average
object size for that database is much higher than average object size of
these two collections we've been talking about. If I were you I would take
a look at the other 10-12 collections and see how they are being used and
if they me impacting anything on your overall system performance.

Post by Panabee
3) How can we confirm how much RAM is available to Mongo?

Check how much RAM is on the machine, check how much other applications
are using. You have 4.11GB memory mapped so if you are accessing all of
your data on a system that has 5GB of RAM however, you said your plan was
2650 and that's only half that and less than what your total data/indexes
total up to... Still, that only explains slower queries when numYields is
non-zero.
4) How can you tell there are pagefaults based on Mongostat? When we

Post by Panabee
look at the faults column, it says 0 all the way through. We would like to
learn so we know how to monitor Mongo ourselves.

If you look at the column "faults" in mongostat - it's frequently 0 but
you can see (at 23:44:33 for instance) it jumps to 29. But mainly I can
see you have indexes on this DB that are almost 40MB plus all your data in
just those two collections is 2.3GB - so *all* of your data definitely
cannot fit in RAM so unless you are querying a very small subset of it you
will get some page faulting. What's not clear is how much your other "bad"
queries (that had to scan a lot of data to find records they needed) were
contributing to your performance problem.

Post by Panabee
5) Since we're already using the _id index against the games query,
but is there anything else we can do to optimize the query? Could
fragmentation in the WoppleGames collection be causing issues?

Panabee

2013-05-28 19:48:43 UTC

Permalink

one other quick question. many of the super slow queries ( > 1000 ms)
involve getmore. is this a tip off to something strange? there query
appears empty as you can see below. you had mentioned before that this was
because getmore is a continuation of a previous query? this query returns
an unusually large number of documents. no player has over 600 games, yet
the query returns 2660 documents. (we only fetch games in the context of a
player.) does the fact that this query returns 2660 docs means somehow our
app is issuing an overly broad query? how can we find the original query
associated with this getmore command? we scanned the log for all instances
of conn13588, but there were a lot of other entries.

here's an example: Sun May 26 00:05:55 [conn13588] getmore
panabee-production.wopple_games query: { query: {}, $snapshot: true }
cursorid:5291841312332131638 ntoreturn:0 exhaust:1 keyUpdates:0 numYields:
77 locks(micros) r:43775 nreturned:2660 reslen:4195066 401ms