[SERVER-16621] emit at mapper may run out of memory Created: 21/Dec/14  Updated: 06/Dec/22  Resolved: 04/Feb/22

Status: Closed
Project: Core Server
Component/s: MapReduce
Affects Version/s: 2.6.6
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Yuan-Yi Chang Assignee: Backlog - Query Execution
Resolution: Done Votes: 0
Labels: pull-request, query-44-grooming
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Assigned Teams:
Query Execution
Participants:

 Description   

The mapper may generate lots of items and each item is kept in-memory at this state. It would be crashed when run out of memory.

NOTE: Skip the checking when using v8 engine (_jsMode: true). The best way is checking at emit function and transfers in memory storage to temp collection. Current state is checking at each document handled because the framework flow designed.



 Comments   
Comment by Esha Bhargava [ 04/Feb/22 ]

Closing these tickets as part of the deprecation of mapReduce.

Comment by David Storch [ 16/Aug/19 ]

I'm changing the issue type from "Bug" to "Improvement", so I'm copying the Steps to Reproduce below:

https://github.com/changyy/mongo-mapper-emit-out-of-memory/

Job is done via jsMode=true.
Mongod crashed via jsMode = false:
https://github.com/changyy/mongo-mapper-emit-out-of-memory/blob/master/index.js#L91

$ tail -f /var/log/mongodb/mongod.log
...
Assertion: 10000:out of memory BufBuilder
The purpose of mapper:

INPUT: ["1", "2", "3"]
OUTPUT: ["1-1", "1-2", "2-1", "1-3", "3-1", "2-2", "2-3", "3-2", "3-3"]
Execute the index.js and restart the mongod. (it crashed because out of memory).

No item_pair_jsmode_off (jsMode = false):

> show collections
item_pair_jsmode_on
rec
system.indexes
> db.item_pair_jsmode_on.count()
4163817

Comment by Ramon Fernandez Marina [ 27/May/15 ]

changyy, upon further examination looks like there's room for improvement in this area, so I'm going to mark the ticket to be considered for planning in a future iteration / development cycle.

Since we can't yet tell whether we'll want to use your approach or a different one I'm going to close the pull request. When the ticket is scheduled, if we decide that your approach is the appropriate one we'll re-open the pull request.

Regards,
Ramón.

Comment by Ramon Fernandez Marina [ 27/May/15 ]

changyy, looks like we let this ticket fall through the cracks – very sorry about that. I'm trying to reproduce the behavior you're seeing, but no luck so far. Will continue to investigate and update the ticket with my findings.

Regards,
Ramón.

Comment by Yuan-Yi Chang [ 01/Jan/15 ]

Hi,

Is there any comment?

I think there is a problem on emit memory usage designed. I add a logger for mapreduce job.

https://github.com/mongodb/mongo/blob/master/src/mongo/db/commands/mr.cpp#L1400
+ LOG(0) << "memory usage: " << _size << ", max: " << _config.maxInMemSize << endl;

You would see the memory usage (_size) is large than _config.maxInMemSize.

Comment by Yuan-Yi Chang [ 23/Dec/14 ]

Hi,

I use pure EC2-m3.medium with 40GB disk space for doing a pure test.
I found the system a little out of memory while running the crashed test case, like:

$ free -m
-bash: fork: Cannot allocate memory

to prevent no more memory situation, please create enough terminals at first.

The full step-by-step in five terminals:

================

terminal #1:
 
$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 14.04.1 LTS
Release:        14.04
Codename:       trusty
 
$ free -m
             total       used       free     shared    buffers     cached
Mem:          3764       1658       2105          0         88       1062
-/+ buffers/cache:        507       3256
Swap:            0          0          0
 
$ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 30037
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 30037
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited
 
$ sudo apt-get update && sudo apt-get -y upgrade && sudo apt-get -y dist-upgrade && sudo apt-get -y autoremove
$ sudo apt-get git nodejs npm scons g++ python-pymongo
$ cd ~/
$ git clone https://github.com/mongodb/mongo.git
$ git log | head -n 3
commit 0ba73576bbe465097c825ba946f561c267465a88
Author: Spencer T Brody <spencer@mongodb.com>
Date:   Fri Dec 19 15:16:02 2014 -0500
$ cd ~/mongo && time scons mongod
...
Install file: "build/linux2/normal/mongo/mongod" as "mongod"
scons: done building targets.
 
real    83m9.116s
user    77m55.717s
sys     4m17.483s
 
$ time scons mongo
...
Install file: "build/linux2/normal/mongo/mongo" as "mongo"
scons: done building targets.
 
real    1m53.680s
user    1m46.608s
sys     0m6.163s
 
$ time scons smokeCppUnittests
...
203 tests succeeded
scons: done building targets.
 
real    65m39.169s
user    58m55.912s
sys     3m31.508s
 
$ time scons dbtest
...
Install file: "build/linux2/normal/mongo/dbtest" as "dbtest"
scons: done building targets.
 
real    14m18.316s
user    13m27.449s
sys     0m34.974s
 
$ time ./dbtest
...
I -        [testsuite] SUCCESS - All tests in all suites passed
I COMMAND  [testsuite] now exiting
I NETWORK  [testsuite] shutdown: going to close listening sockets...
I NETWORK  [testsuite] shutdown: going to flush diaglog...
I NETWORK  [testsuite] shutdown: going to close sockets...
I STORAGE  [testsuite] shutdown: waiting for fs preallocator...
I STORAGE  [testsuite] shutdown: final commit...
I STORAGE  [testsuite] shutdown: closing all files...
I STORAGE  [testsuite] closeAllFiles() finished
I JOURNAL  [testsuite] journalCleanup...
I JOURNAL  [testsuite] removeJournalFiles
I STORAGE  [testsuite] shutdown: removing fs lock...
I COMMAND  [testsuite] dbexit:  rc: 0
 
real    6m5.872s
user    4m15.567s
sys     0m28.863s
 
 
terminal #2: run mongod instance
 
$ df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/xvda1       40G   20G   19G  52% /
 
$ free -m
             total       used       free     shared    buffers     cached
Mem:          3764        272       3492          0         31        159
-/+ buffers/cache:         80       3683
Swap:            0          0          0
 
$ mkdir -p /tmp/mongo/db/log 
$ ~/mongo/mongod --port 27017 --dbpath /tmp/mongo/db --logpath /tmp/mongo/log
 
 
terminal #3: cat mongod log
$ tail -f /tmp/mongo/log
 
terminal #4: run crashed test case
 
$ nodejs --version
v0.10.25
$ git clone https://github.com/changyy/mongo-mapper-emit-out-of-memory.git
$ cd mongo-mapper-emit-out-of-memory && npm install
...
async@0.9.0 node_modules/async
 
mongodb@1.4.26 node_modules/mongodb
├── readable-stream@1.0.33 (isarray@0.0.1, inherits@2.0.1, string_decoder@0.10.31, core-util-is@1.0.1)
├── kerberos@0.0.7 (nan@1.3.0)
└── bson@0.2.16 (nan@1.3.0)
 
mongoose@3.8.21 node_modules/mongoose
├── regexp-clone@0.0.1
├── sliced@0.0.5
├── muri@0.3.1
├── hooks@0.2.1
├── mpath@0.1.1
├── mpromise@0.4.3
├── ms@0.1.0
├── mquery@0.8.0 (debug@0.7.4)
└── mongodb@1.4.12 (readable-stream@1.0.33, kerberos@0.0.4, bson@0.2.16)
 
$ NODE_PATH=node_modules nodejs crashed_only.js
{ [Error: Cannot find module '../build/Release/bson'] code: 'MODULE_NOT_FOUND' }
js-bson: Failed to load c++ bson extension, using pure JS version
^C
 
$ vim node_modules/mongoose/node_modules/mongodb/node_modules/bson/ext/index.js
        // Attempt to load the release bson version
        try {
                //bson = require('../build/Release/bson');
                bson = require('bson');
        } catch (err) {
                console.dir(err)
                console.error("js-bson: Failed to load c++ bson extension, using pure JS version");
                bson = require('../lib/bson/bson');
        }
 
$ time NODE_PATH=node_modules nodejs crashed_only.js
 
================
 
 
 
While running the crashed test case, you would see the result of terminal #4:
 
#4
====
[Error: connection closed]
 
 
 
[DONE] RESET DATABASE
[DONE] generate test data
[DONE] jsMode is false
 
real    10m6.471s
user    0m0.658s
sys     0m0.074s
 
That's mean the mongod conenction break: [Error: connection closed]
 
the result of #2 terminal:
====
$ ~/mongo/mongod --port 27017 --dbpath /tmp/mongo/db --logpath /tmp/mongo/log
src/third_party/gperftools-2.2/src/central_freelist.cc:333] tcmalloc: allocation failed 16384
 
Now, let's check the mongod.log: $ cat /tmp/mongo/log
 
F -        [conn12] out of memory. 0xeec289 0xeebdb9 0x138999f 0x96507b 0x95f88d 0x96121b 0x965b89 0x9b7224 0x9b80ad 0x9b8acc 0xb74bea 0xa8d215 0x801080 0xeac5a1 0x7f6c26f71182 0x7f6c26071efd
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"400000","o":"AEC289"},{"b":"400000","o":"AEBDB9"},{"b":"400000","o":"F8999F"},{"b":"400000","o":"56507B"},{"b":"400000","o":"55F88D"},{"b":"400000","o":"56121B"},{"b":"400000","o":"565B89"},{"b":"400000","o":"5B7224"},{"b":"400000","o":"5B80AD"},{"b":"400000","o":"5B8ACC"},{"b":"400000","o":"774BEA"},{"b":"400000","o":"68D215"},{"b":"400000","o":"401080"},{"b":"400000","o":"AAC5A1"},{"b":"7F6C26F69000","o":"8182"},{"b":"7F6C25F77000","o":"FAEFD"}],"processInfo":{ "mongodbVersion" : "2.8.0-rc4-pre-", "gitVersion" : "0ba73576bbe465097c825ba946f561c267465a88", "uname" : { "sysname" : "Linux", "release" : "3.13.0-43-generic", "version" : "#72-Ubuntu SMP Mon Dec 8 19:35:06 UTC 2014", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "DED90C7AB2CAE8C9EC7DD2A8D2F25FB8A1BB3FF3" }, { "b" : "7FFF17CAD000", "elfType" : 3, "buildId" : "9D77366C6409A9EA266179080FA7C779EEA8A958" }, { "b" : "7F6C26F69000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3, "buildId" : "FE662C4D7B14EE804E0C1902FB55218A106BC5CB" }, { "b" : "7F6C26D61000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3, "buildId" : "92FCF41EFE012D6186E31A59AD05BDBB487769AB" }, { "b" : "7F6C26B5D000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3, "buildId" : "C1AE4CB7195D337A77A3C689051DABAA3980CA0C" }, { "b" : "7F6C26859000", "path" : "/usr/lib/x86_64-linux-gnu/libstdc++.so.6", "elfType" : 3, "buildId" : "19EFDDAB11B3BF5C71570078C59F91CF6592CE9E" }, { "b" : "7F6C26553000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3, "buildId" : "574C6350381DA194C00FF555E0C1784618C05569" }, { "b" : "7F6C2633D000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3, "buildId" : "8D0AA71411580EE6C08809695C3984769F25725B" }, { "b" : "7F6C25F77000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3, "buildId" : "7603ABF78951CC138A4105F4516B075D859DFC9A" }, { "b" : "7F6C27187000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "9F00581AB3C73E3AEA35995A0C50D24D59A01D47" } ] }}
 mongod(_ZN5mongo15printStackTraceERSo+0x29) [0xeec289]
 mongod(_ZN5mongo29reportOutOfMemoryErrorAndExitEv+0x49) [0xeebdb9]
 mongod(tc_new+0x1AF) [0x138999f]
 mongod(_ZNSt8_Rb_treeIN5mongo7BSONObjESt4pairIKS1_St6vectorIS1_SaIS1_EEESt10_Select1stIS7_ENS0_2mr11TupleKeyCmpESaIS7_EE22_M_emplace_hint_uniqueIIRKSt21piecewise_construct_tSt5tupleIIRS3_EESI_IIEEEEESt17_Rb_tree_iteratorIS7_ESt23_Rb_tree_const_iteratorIS7_EDpOT_+0x1B) [0x96507b]
 mongod(_ZN5mongo2mr5State4_addEPSt3mapINS_7BSONObjESt6vectorIS3_SaIS3_EENS0_11TupleKeyCmpESaISt4pairIKS3_S6_EEERS9_+0x15D) [0x95f88d]
 mongod(_ZN5mongo2mr5State14reduceInMemoryEv+0xCB) [0x96121b]
 mongod(_ZN5mongo2mr16MapReduceCommand3runEPNS_16OperationContextERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x9E9) [0x965b89]
 mongod(_ZN5mongo12_execCommandEPNS_16OperationContextEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x34) [0x9b7224]
 mongod(_ZN5mongo7Command11execCommandEPNS_16OperationContextEPS0_iPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xC4D) [0x9b80ad]
 mongod(_ZN5mongo12_runCommandsEPNS_16OperationContextEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x28C) [0x9b8acc]
 mongod(_ZN5mongo8runQueryEPNS_16OperationContextERNS_7MessageERNS_12QueryMessageERNS_5CurOpES3_b+0x76A) [0xb74bea]
 mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortEb+0xB55) [0xa8d215]
 mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xE0) [0x801080]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x431) [0xeac5a1]
 libpthread.so.0(+0x8182) [0x7f6c26f71182]
 libc.so.6(clone+0x6D) [0x7f6c26071efd]
-----  END BACKTRACE  -----

Comment by Yuan-Yi Chang [ 23/Dec/14 ]

Hi,

The reason of mongod crashed is mapper with jsMode=false would use the native memory to keep the result in C++ map structure.

I found the code would write the result to collection when 100 input document handled:
https://github.com/mongodb/mongo/blob/master/src/mongo/db/commands/mr.cpp#L1401

Is there any memory usage checking? If one document would generate lots of results, the mongod may be crashed with out of memory.

I added a crashed only test case:
https://github.com/changyy/mongo-mapper-emit-out-of-memory/blob/master/crashed_only.js

You can enlarge the result of one document handled from the number "512" to other big number.
https://github.com/changyy/mongo-mapper-emit-out-of-memory/blob/master/crashed_only.js#L31

Comment by Yuan-Yi Chang [ 23/Dec/14 ]

Hi,

My test env:

https://github.com/changyy/mongo-mapper-emit-out-of-memory
AWS EC2 m3.medium:

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04.1 LTS
Release: 14.04
Codename: trusty

$ free -m
total used free shared buffers cached
Mem: 3951 665 3286 9 4 42
-/+ buffers/cache: 618 3333
Swap: 0 0 0

$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 31534
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 31534
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
Mongod Version:

$ mongo
MongoDB shell version: 2.6.6
connecting to: test
> db.version()
2.6.6
> quit()

When I running the test case, it may be "Assertion: 10000:out of memory BufBuilder" with mongod connection failed. The mongod crashed sometime with /var/log/mongod.log:

2014-12-19T09:03:04.166+0000 [conn73] SEVERE: out of memory, printing stack and exiting:
0x11fca91 0x11fbd88 0x125057d 0x1659bf0 0x99ca03 0x99e25a 0x98d5a2 0x98dd52 0x98e154 0x11672bf 0x1158f89 0x13410b2 0x464bd906362
/usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11fca91]
/usr/bin/mongod() [0x11fbd88]
/usr/bin/mongod() [0x125057d]
/usr/bin/mongod(tc_new+0x10) [0x1659bf0]
/usr/bin/mongod(ZNSt8_Rb_treeIN5mongo7BSONObjESt4pairIKS1_St6vectorIS1_SaIS1_EEESt10_Select1stIS7_ENS0_2mr11TupleKeyCmpESaIS7_EE9_M_insertEPSt18_Rb_tree_node_baseSF_RKS7+0x33) [0x99ca03]
/usr/bin/mongod(ZNSt8_Rb_treeIN5mongo7BSONObjESt4pairIKS1_St6vectorIS1_SaIS1_EEESt10_Select1stIS7_ENS0_2mr11TupleKeyCmpESaIS7_EE13insert_uniqueESt17_Rb_tree_iteratorIS7_ERKS7+0x82a) [0x99e25a]
/usr/bin/mongod(ZN5mongo2mr5State4_addEPSt3mapINS_7BSONObjESt6vectorIS3_SaIS3_EENS0_11TupleKeyCmpESaISt4pairIKS3_S6_EEERS9+0x4c2) [0x98d5a2]
/usr/bin/mongod(_ZN5mongo2mr5State4emitERKNS_7BSONObjE+0x32) [0x98dd52]
/usr/bin/mongod(_ZN5mongo2mr9fast_emitERKNS_7BSONObjEPv+0xd4) [0x98e154]
/usr/bin/mongod(_ZN5mongo7V8Scope14nativeCallbackEPS0_RKN2v89ArgumentsE+0x68f) [0x11672bf]
/usr/bin/mongod(_ZN5mongo7V8Scope10v8CallbackERKN2v89ArgumentsE+0x89) [0x1158f89]
/usr/bin/mongod() [0x13410b2]
[0x464bd906362]

Comment by Matt Kangas [ 22/Dec/14 ]

Hi changyy,

Thank you for the patch and the test case. I have tried to reproduce the "Assertion: 10000" you encountered with mongodb, nodejs v0.10.34 on Ubuntu 12.04. The test completes successfully in about 6m40s.

I've tried mongodb versions v2.6.3 and v2.6.6. Both pass the test you've provided.

Any thoughts on why I'm unable to reproduce your results?
(What LANG do you have configured?)

FYI, here is the assertion you are hitting. It is a "msgassert" which not fatal for the server, only fatal for the operation being performed.

src/mongo/bson/util/builder.h:123:                    msgasserted(10000, "out of memory BufBuilder");

Comment by Yuan-Yi Chang [ 21/Dec/14 ]

Patch:

https://github.com/mongodb/mongo/pull/889

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