[SERVER-13794] Unused snapshot history consuming significant heap space Created: 30/Apr/14  Updated: 11/Jul/16  Resolved: 07/May/14

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: 2.6.0
Fix Version/s: 2.6.2, 2.7.1

Type: Bug Priority: Major - P3
Reporter: James Wahlin Assignee: James Wahlin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File massif.out    
Issue Links:
Depends
Related
is related to SERVER-13743 Mongod killed by linux OOM under long... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Completed:
Sprint: Server 2.7.1
Participants:

 Description   
Issue Status as of May 16, 2014

ISSUE SUMMARY
mongod consumes significant heap space on unused snapshot history when snapshots are enabled. This increased memory use is not a leak, and is proportional to the number of collections.

USER IMPACT
Users will see increased memory usage by mongod processes.

WORKAROUNDS
N/A

AFFECTED VERSIONS
All 2.4 and 2.6 MongoDB production releases are affected by this isse.

FIX VERSION
The fix is included in the 2.6.2 production release.

RESOLUTION DETAILS
The snapshot thread, which provides historical collection level and lock statistics for use by the web interface, is only needed when HTTP is enabled. To avoid this extra memory consumption, disable the HTTP interface.

Original description

We saw a case where an upgrade from 2.4 to 2.6 led to non-mapped memory peak growing for all 2.6.0 members of a replica set. Taking the data set in question and 15 minute sampling of read operations I was able to reproduce 200MB growth. Heap profiling in Valgrind led to discovery that this memory was being consumed by the snapshots thread (db/stats/snapshots.h/.cpp).

The snapshots thread currently maintains an array of 100 snapshots. Each snapshot contains collection level usage data, the size of which grows with each collection contained within a mongod instance. The data set used to reproduce contains 3588 collections.

The growth occurs in the following valgrind massif stack. The full ms_print valgrind output will be attached as well.

99.41% (153,881,596B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc.
->55.57% (86,016,800B) 0x138BE28: mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther>::Area::Area(mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther>::Area const&) (unordered_fast_key_table_internal.h:34)
| ->55.57% (86,016,800B) 0x138BC40: mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther>::copyTo(mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther>*) const (unordered_fast_key_table_internal.h:127)
|   ->55.57% (86,016,800B) 0x138BB85: mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther>::operator=(mongo::UnorderedFastKeyTable<mongo::StringData, std::string, mongo::Top::CollectionData, mongo::StringData::Hasher, mongo::StringMapDefaultEqual, mongo::StringMapDefaultConvertor, mongo::StringMapDefaultConvertorOther> const&) (unordered_fast_key_table.h:94)
|     ->55.57% (86,016,800B) 0x138B7B1: mongo::StringMap<mongo::Top::CollectionData>::operator=(mongo::StringMap<mongo::Top::CollectionData> const&) (string_map.h:46)
|       ->55.57% (86,016,800B) 0x138AFCC: mongo::Top::cloneMap(mongo::StringMap<mongo::Top::CollectionData>&) const (top.cpp:130)
|         ->55.57% (86,016,800B) 0x13878C4: mongo::SnapshotData::takeSnapshot() (snapshots.cpp:47)
|           ->55.57% (86,016,800B) 0x1387E03: mongo::Snapshots::takeSnapshot() (snapshots.cpp:83)
|             ->55.57% (86,016,800B) 0x13881D6: mongo::SnapshotThread::run() (snapshots.cpp:128)
|               ->55.57% (86,016,800B) 0x151E2B8: mongo::BackgroundJob::jobBody() (background.cpp:147)
|                 ->55.57% (86,016,800B) 0x1521793: boost::_mfi::mf0<void, mongo::BackgroundJob>::operator()(mongo::BackgroundJob*) const (mem_fn_template.hpp:49)
|                   ->55.57% (86,016,800B) 0x15216F6: void boost::_bi::list1<boost::_bi::value<mongo::BackgroundJob*> >::operator()<boost::_mfi::mf0<void, mongo::BackgroundJob>, boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf0<void, mongo::BackgroundJob>&, boost::_bi::list0&, int) (bind.hpp:253)
|                     ->55.57% (86,016,800B) 0x15216A5: boost::_bi::bind_t<void, boost::_mfi::mf0<void, mongo::BackgroundJob>, boost::_bi::list1<boost::_bi::value<mongo::BackgroundJob*> > >::operator()() (bind_template.hpp:20)
|                       ->55.57% (86,016,800B) 0x152166A: boost::detail::thread_data<boost::_bi::bind_t<void, boost::_mfi::mf0<void, mongo::BackgroundJob>, boost::_bi::list1<boost::_bi::value<mongo::BackgroundJob*> > > >::run() (thread.hpp:62)
|                         ->55.57% (86,016,800B) 0x15C11E8: thread_proxy (thread.cpp:121)
|                           ->55.57% (86,016,800B) 0x4E36180: start_thread (pthread_create.c:312)
|                             ->55.57% (86,016,800B) 0x596730B: clone (clone.S:111)
|                               



 Comments   
Comment by Githook User [ 16/May/14 ]

Author:

{u'name': u'James Wahlin', u'email': u'james.wahlin@10gen.com'}

Message: SERVER-13794 - only start snapshot thread on isHttpInterfaceEnabled

Signed-off-by: Matt Kangas <matt.kangas@mongodb.com>
(cherry picked from commit 3926d4db3aab1d65f381afcb39783da0edaa2b7e)
Branch: v2.6
https://github.com/mongodb/mongo/commit/3fa0ec160da4a0858faf63f1d7ce600254594b37

Comment by Githook User [ 07/May/14 ]

Author:

{u'name': u'James Wahlin', u'email': u'james.wahlin@10gen.com'}

Message: SERVER-13794 - only start snapshot thread on isHttpInterfaceEnabled

Signed-off-by: Matt Kangas <matt.kangas@mongodb.com>
Branch: master
https://github.com/mongodb/mongo/commit/3926d4db3aab1d65f381afcb39783da0edaa2b7e

Comment by James Wahlin [ 01/May/14 ]

TL;DR:

  1. There are a few ways we may be able to reduce the memory footprint used for the REST api collection stats.
  2. Space consumed is bounded by # of collections. For 3588 collections, 182MB of memory is used.

The reason for the memory consumption seen here is:

  1. We store collection level counters and lock information.
  2. These stats are stored in a hash table mapping collection to stats (with the hash table starting at 20 entries and doubling in size each time capacity is reached).
  3. The snapshot thread stores 100 copies of the hash table.

The snapshot information appears to be used only by the REST api. The options I see to reduce space consumed are:

  1. Reduce the # of snapshots
    • The only place we use more than the last 2 snapshots is in Snapshots::outputLockInfoHTML(). outputLockInfoHTML delivers write lock % to the REST api - providing the last 100 4-second periods. The values provided however depend on _totalWriteLockedTime being assigned a value when the snapshot is taken. At present we have the only line that sets _totalWriteLockedTime commented out, so the value will always be 0.
  2. Don't start the snapshot thread when the REST api is not enabled (need to investigate further whether this has side affects).
  3. Reduce the footprint of each snapshot. We store collection statistics in a hash table to allow for fast statistic writes. In the snapshots.cpp and snapshots_webplugins.cpp where we access we don't make use of the fast lookups and instead iterate over the entire collection set. Given that we could store collection stats in a more condense data structure.
    • This is not an appealing option as it would be considerable work
  4. Remove these statistics from the REST api
    • My guess is not an option

A few final things to note:

  1. This is not a 2.6 regression. The memory usage pattern seen here existing in 2.4 as well.
  2. The memory used is not a leak and is bounded by number of collections. For 3588 collections we see 182MB of space consumed.
Comment by James Wahlin [ 30/Apr/14 ]

dan@10gen.com - I see memory growth in 2.4.10 as well but less significant than in 2.6.0. Here are the stats from my test case:

2.4.10 2.6.0 2.6.0 w/ snapshots disabled
742MB 816MB 634MB
Comment by James Wahlin [ 30/Apr/14 ]

Testing on 2.4.10 now.

Comment by Daniel Pasette (Inactive) [ 30/Apr/14 ]

can you check this repro test on 2.4.10?

Comment by James Wahlin [ 30/Apr/14 ]

Attached Valgrind massif output

Generated at Thu Feb 08 03:32:55 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.