TTL index cause high DB lock

974 views
Skip to first unread message

David Wang

unread,
Feb 13, 2014, 1:32:07 PM2/13/14
to mongod...@googlegroups.com

Mongo Newbie here.

It appear that after I created TTL index; mongo db lock rate shots up.
Just installed MMS about a hour ago.  I only want to keep the data for 4 days (60x60x24x4)=345600.

Delete seems to be a very expensive operation in Mongodb?
Am I not using TTL index correctly?
How can I quickly delete/expire bunch of data in ok size collection(26+ millions records)?

Very similar Q as posted in this thread:

https://groups.google.com/forum/#!searchin/mongodb-user/ttl$20lock/mongodb-user/2W2FieUAP6s/ZIiuUD81hEkJ

Capped collection doesn't work well for me as it's not precise and I would like to shard my collections eventually.

possible solution but I will lose records in the mean time?

http://edgar.tumblr.com/post/38232292665/how-to-delete-large-amount-of-data-of-a-mongodb

Server/Mongo info:

3.5.0-45-generic #68~precise1-Ubuntu SMP

MongoDB shell version: 2.4.9

collection stats:

> db.test.stats()

{

"ns" : "dw.test",

"count" : 26120286,

"size" : 4666195584,

"avgObjSize" : 178.64259158571235,

"storageSize" : 5503524752,

"numExtents" : 25,

"nindexes" : 6,

"lastExtentSize" : 536600560,

"paddingFactor" : 1.0000000000629252,

"systemFlags" : 0,

"userFlags" : 1,

"totalIndexSize" : 8035102992,

"indexSizes" : {

"_id_" : 874848352,

"a_1_b_1_c_1" : 2294038432,

"d_1" : 1528020816,

"epoch_1" : 1224290592,

"g_1" : 1298659488,

"h_1" : 815245312

},

"ok" : 1

}

Before creating TTL index:

insert  query update delete getmore command flushes mapped  vsize    res faults   locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time 

    *0     *0   1877     *0       0  1879|0       1  78.6g   158g  11.7g      0    dw:26.4%          0       0|0     0|0   588k   192k     3   11:19:33 

    *0     *0   1880     *0       0  1880|0       1  78.6g   158g  11.7g      0    dw:26.2%          0       0|0     0|1   588k   193k     3   11:19:34 

    *0     *0   1913     *0       0  1914|0       1  78.6g   158g  11.7g      0    dw:27.6%          0       0|0     0|1   599k   196k     3   11:19:35 

    *0     *0   1931     *0       0  1932|0       1  78.6g   158g  11.7g      0    dw:25.6%          0       0|0     0|1   605k   198k     3   11:19:36 

After creating TTL index:
ts: time stamp
"ts" : ISODate("2014-02-01T07:13:26.139Z")"
db.test.ensureIndex({ts:1}, {expireAfterSeconds: 345600 })

insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time 

    *0     *0     14     *0       0    15|0       1  79.1g   159g  13.8g      0  dw:257.3%          0       0|0     0|1     4k     4k     3   11:42:58 

    *0     *0     16     *0       0    17|0       1  79.1g   159g  13.9g      0  dw:198.7%          0       2|0     0|0     5k     4k     3   11:43:00 

    *0     *0     33     *0       0    34|0       2  79.1g   159g  13.8g      0  dw:194.6%          0       1|1     0|0    10k     6k     3   11:43:02 

    *0     *0     24     *0        0    25|0       1  79.1g   159g  13.9g      0  dw:197.6%          0       2|0     0|1     7k     5k     3   11:43:03 

Dropped TTL index:  Everything is back to normal:

db.test.dropIndex({"ts":1})

insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time 

    *0     *0   1838     *0       0  1839|0       1  79.1g   158g  3.26g      0   dw:24.2%          0       0|0     0|0   583k   188k     4   13:19:23 

    *0     *0    628     *0       0   628|0       0  79.1g   158g  3.24g      0    dw:8.3%          0       0|0     0|1   199k    66k     4   13:19:25 

    *0     *0   2072     *0       0  2074|0       1  79.1g   158g  3.25g      0   dw:27.4%          0       0|0     0|0   657k   212k     4   13:19:26 

    *0      4    604     *0       0   604|0       0  79.1g   158g  3.23g      0    dw:8.1%          0       0|0     0|0   191k    64k     4   13:19:28 

    *0     *0   2096     *0       0  2098|0       1  79.1g   158g  3.26g      0   dw:26.2%          0       0|0     0|0   665k   215k     4   13:19:29 

Andrew Ryder

unread,
Feb 14, 2014, 1:44:32 AM2/14/14
to mongod...@googlegroups.com
Hi there!

Your "expireAfterSeconds" equates to 4 days and you have over 26 million documents. How many of these have a "ts" field older than 4 days? Can you (or did you) run a db.stats() after the TTL index ran for awhile?

The reason I ask is because it looks like the index started deleting stuff straight away and was still busily churning when it was removed. Delete operations take the write-lock. mongostat doesn't show deletions occurring as a result of internal processes because it isn't privy to those. You don't seem to be running a replica-set so unfortunately you can't use mongostat on a secondary to observe the deletions occurring either. The db.stats() will show if the count and size is going down though.

On another note, I would suggest you enable usePowerOf2Sizes for this collection - this advice is predicated on the idea that this collection has a high churn rate - this setting will likely improve performance and storage re-use.

Kind regards,
Andrew

Glenn Maynard

unread,
Feb 14, 2014, 9:06:54 AM2/14/14
to mongod...@googlegroups.com
On Fri, Feb 14, 2014 at 12:44 AM, Andrew Ryder <andrew...@10gen.com> wrote:
The reason I ask is because it looks like the index started deleting stuff straight away and was still busily churning when it was removed. Delete operations take the write-lock. mongostat doesn't show deletions occurring as a result of internal processes because it isn't privy to those. You don't seem to be running a replica-set so unfortunately you can't use mongostat on a secondary to observe the deletions occurring either. The db.stats() will show if the count and size is going down though.

If TTL indexes reduce mongostat's inaccuracy, it seems like it's better to just roll your own periodic job to run the deletes.  (From what I can tell, it seems like that's basically how TTL works anyway.)  Are the deletes invisible to db.currentOp() and profiling too?

--
Glenn Maynard

dw

unread,
Feb 14, 2014, 10:00:20 AM2/14/14
to mongod...@googlegroups.com
Hi Andrew:

Thank you for the response!!

Each document have 2 time field:  ts(date) and epoch(int) 
the 2 Time stamp fields are the document creation time.

sample output:
db.test.find({epoch:{$lte:1392042213}}, {epoch:1,ts:1,_id:0}).sort({epoch:1}).limit(20)
{ "ts" : ISODate("2014-01-29T07:53:50.106Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.665Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.907Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.907Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.105Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.324Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.588Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.105Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.320Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.907Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.908Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.906Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.516Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.906Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.322Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.907Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.906Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.319Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.107Z"), "epoch" : 1390982030 }
{ "ts" : ISODate("2014-01-29T07:53:50.322Z"), "epoch" : 1390982030 }

Potential expired documents count:
db.test.find({epoch:{$lte:1392042213}}).count()
3459143

Just enable usePowerOf2Sizes on the collection.  I thought creating TTL index automaticaly enable usePowerOf2Size?
db.runCommand( {collMod: "test", usePowerOf2Sizes : true })

"All collections with an index using the expireAfterSeconds option have usePowerOf2Sizes enabled. Users cannot modify this setting. As a result of enabling usePowerOf2Sizes, MongoDB must allocate more disk space relative to data size. This approach helps mitigate the possibility of storage fragmentation caused by frequent delete operations and leads to more predictable storage use patterns"

I recalled that the collection document count did go down but there are ~800-1000 upsert per seconds.
When the DB locked rate are that high; I am afraid that I am losing data.

I can run a manual "cron type" delete but that would locked the DB as well?

Is there any best practices to follow when the db is under constant high read/write/delete operations?

Thanks
DW

Asya Kamsky

unread,
Feb 19, 2014, 7:47:27 PM2/19/14
to mongodb-user
mongostat CRUD ops show the number of CRUD operations initiated by the
client/end user/application. They exclude (intentionally) internally
triggered CRUD operations. There are other places where those are
visible, for example db.serverStatus() has a section that shows how
many passes TTL thread did and how many documents it deleted.

Asya
> --
> --
> You received this message because you are subscribed to the Google
> Groups "mongodb-user" group.
> To post to this group, send email to mongod...@googlegroups.com
> To unsubscribe from this group, send email to
> mongodb-user...@googlegroups.com
> 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...@googlegroups.com.
> For more options, visit https://groups.google.com/groups/opt_out.

Asya Kamsky

unread,
Feb 19, 2014, 7:49:28 PM2/19/14
to mongodb-user
Yes, creating TTL index will automatically turn on usePowerOf2Sizes.

But consider what you asked the DB to do - you said please delete 3.5
Million documents out of 26 million (when it looks like you're
normally touching only about 2,000 documents per second).

I don't think you can reasonably expect that sort of operation not to
have any effect on your "normal" workload.

Asya

dw

unread,
Feb 19, 2014, 10:54:13 PM2/19/14
to mongod...@googlegroups.com
Thank you Asya:

Manual deleting attempt of large amount of documents cause high DB lock as well.  
Is there any good strategy for massive delete while maintain update throughput?

Main reason for trying TTL index was a desperate/"grasping for straw" attempt hope that MongoDB perform TTL delete more efficiently.
After reading the documentation more closely show that I was in error.

This is all part of getting to know MongoDB better.  Expiring data is an after thought.
I recreated the collection with TTL index in place and it have been performing beautifully.
Lesson learned here is to know the data access pattern well and plan ahead.

so at most 2000 update a second x 60 seconds = 120k delete each time TTL delete run.

db.serverStatus() show TTL delete in action.

"ttl" : {
"deletedDocuments" : NumberLong(746805),
"passes" : NumberLong(7651)
}


Thanks again.
David

Asya Kamsky

unread,
Feb 19, 2014, 10:55:39 PM2/19/14
to mongodb-user
Glad you were able to figure it out - and it's good you were able to
move on with TTL collection.
It's good at deleting things over time as they expire, but of course
trying to delete huge amount of data at once has to pay the price
somewhere! :)

Asya
Reply all
Reply to author
Forward
0 new messages