perf: Requests get slower, when queues have a lot of messages

[Malini Kamalambal]

The requests are taking long to complete, when the queue has a lot of pre-existing messages.

Steps to Repro:
1. Run the tsung benchmark tests
2. Run a tsung test to pre-load the db with a lot of messages , on a specific queue
3. Re-run the tsung benchmark tests

Expected Results:
There will no significant perf degradation between Steps 1 & 3.

Actual Results:
The response times get slower in Step 3 (compared to Step 1)

[Ozgur Akan (ozgurakan)]

When we have 500K messages, claim messages takes up to 12 seconds to return. On mongodb site it is 1-2 seconds run time.

These are some of the slow queries;

{ "$query" : { "q" : "q19" , "p" : "806067" , "c.e" : { "$lte" : { "$date" : "2013-08-27T02:03:51.366Z"}} , "e" : { "$gt" : { "$date" : "2013-08-27T02:03:51.366Z"}}} , "$hint" : { "q" : 1 , "p" : 1 , "k" : 1 , "e" : 1 , "c.e" : 1} , "$orderby" : { "k" : 1}}
{ "$query" : { "q" : "q1" , "p" : "806067" , "c.e" : { "$lte" : { "$date" : "2013-08-27T02:03:51.085Z"}} , "e" : { "$gt" : { "$date" : "2013-08-27T02:03:51.085Z"}}} , "$hint" : { "q" : 1 , "p" : 1 , "k" : 1 , "e" : 1 , "c.e" : 1} , "$orderby" : { "k" : 1}}
{ "$query" : { "q" : "q13" , "p" : "806067" , "c.e" : { "$lte" : { "$date" : "2013-08-27T02:03:50.910Z"}} , "e" : { "$gt" : { "$date" : "2013-08-27T02:03:50.910Z"}}} , "$hint" : { "q" : 1 , "p" : 1 , "k" : 1 , "e" : 1 , "c.e" : 1} , "$orderby" : { "k" : 1}}
{ "$query" : { "q" : "q14" , "p" : "806067" , "c.e" : { "$lte" : { "$date" : "2013-08-27T01:58:14.643Z"}} , "e" : { "$gt" : { "$date" : "2013-08-27T01:58:14.643Z"}}} , "$hint" : { "q" : 1 , "p" : 1 , "k" : 1 , "e" : 1 , "c.e" : 1} , "$orderby" : { "k" : 1}}
{ "$query" : { "q" : "q5" , "p" : "806067" , "c.e" : { "$lte" : { "$date" : "2013-08-27T02:03:50.925Z"}} , "e" : { "$gt" : { "$date" : "2013-08-27T02:03:50.925Z"}}} , "$hint" : { "q" : 1 , "p" : 1 , "k" : 1 , "e" : 1 , "c.e" : 1} , "$orderby" : { "k" : 1}}

Details on one of these (took 940ms to run);
{
        "op" : "query",
        "ns" : "marconi.messages",
        "query" : {
                "$query" : {
                        "q" : "q9",
                        "p" : "806067",
                        "c.e" : {
                                "$lte" : ISODate("2013-08-27T02:03:51.072Z")
                        },
                        "e" : {
                                "$gt" : ISODate("2013-08-27T02:03:51.072Z")
                        }
                },
                "$hint" : {
                        "q" : 1,
                        "p" : 1,
                        "k" : 1,
                        "e" : 1,
                        "c.e" : 1
                },
                "$orderby" : {
                        "k" : 1
                }
        },
        "cursorid" : NumberLong("2177673334012593318"),
        "ntoreturn" : 10,
        "ntoskip" : 0,
        "nscanned" : 21255,
        "keyUpdates" : 0,
        "numYield" : 20,
        "lockStats" : {
                "timeLockedMicros" : {
                        "r" : NumberLong(906938),
                        "w" : NumberLong(0)
                },
                "timeAcquiringMicros" : {
                        "r" : NumberLong(920436),
                        "w" : NumberLong(20696)
                }
        },
        "nreturned" : 10,
        "responseLength" : 1510,
        "millis" : 940,
        "ts" : ISODate("2013-08-27T02:03:52.140Z"),
        "client" : "10.177.38.136",
        "allUsers" : [ ],
        "user" : ""
}

[Kurt Griffiths (kgriffs)]

I am going to try try emoving range query on expiration and removing thresholding from GC, then just relying on the GC to clean up expired messages.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/44340

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/44340
Committed: http://github.com/stackforge/marconi/commit/72974b7be1ed66476ab7027bb5b3eb6c9c3e2340
Submitter: Jenkins
Branch: master

commit 72974b7be1ed66476ab7027bb5b3eb6c9c3e2340
Author: kgriffs <email address hidden>
Date: Wed Aug 28 20:30:08 2013 -0500

    fix: Requests get slower when queues have a lot of messages

    The primary culprit was an additional scan operation
    in the MongoDB driver's _list(...) method, triggered by
    a range query on the message's expiration date.

    This patch removes that field from the index, so the filtering
    is done using a single scan pass. It also removes 'e' from the
    index used for counting messages, since in testing it was
    slightly faster to leave it out (and should also slightly speed
    up insertion time since it's once less index field that mongo
    has to worry about.)

    Also in this patch, the order of the project and
    queue name fields were swapped in the index in order
    to optimize for selectivity. In addition, some minor
    edits were made for style and correctness.

    Finally, this patch also removes thresholding from
    the GC so that we don't have expired messages hanging
    around for a long time that have to be filtered out.

    Change-Id: Ie4bd125e966612f4a8022fd6af133314d05fe428
    Closes-Bug: #1216950