[SERVER-19061] insert data fast, server crash with cannot allocate memory message Created: 20/Jun/15  Updated: 14/Apr/16  Resolved: 21/Jun/15

Status: Closed
Project: Core Server
Component/s: Admin, WiredTiger
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: THUAN Assignee: Ramon Fernandez Marina
Resolution: Duplicate Votes: 0
Labels: crash
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Centos 7


Attachments: PNG File Screen Shot 2015-06-20 at 8.32.35 AM.png     PNG File Screen Shot 2015-06-20 at 8.33.05 PM.png    
Issue Links:
Duplicate
duplicates SERVER-17364 Idle cursors shouldn't hold storage e... Closed
Operating System: Linux
Participants:

 Description   

2015-06-20T08:31:32.408+0700 E STORAGE  [conn40] WiredTiger (12) [1434763892:408515][27568:0x7f514db39700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-06-20T08:31:32.408+0700 I -        [conn40] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-06-20T08:31:32.419+0700 I CONTROL  [conn40] 
 0xf5e489 0xefd4b1 0xee3afa 0xd81160 0xd81636 0xd7cade 0xd7cb25 0xd6b415 0xa84d25 0xa0de30 0xa39e0c 0xbd09a4 0xbd0d54 0xbd13bd 0x9b1bdd 0x9b33bc 0x9b38fb 0x9b62ad 0x9d8474 0x9d93fd 0x9da10b 0xb9ef5a 0xab5290 0x80fc1d 0xf115bb 0x7f516052ddf5 0x7f515efdc1ad
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"400000","o":"B5E489"},{"b":"400000","o":"AFD4B1"},{"b":"400000","o":"AE3AFA"},{"b":"400000","o":"981160"},{"b":"400000","o":"981636"},{"b":"400000","o":"97CADE"},{"b":"400000","o":"97CB25"},{"b":"400000","o":"96B415"},{"b":"400000","o":"684D25"},{"b":"400000","o":"60DE30"},{"b":"400000","o":"639E0C"},{"b":"400000","o":"7D09A4"},{"b":"400000","o":"7D0D54"},{"b":"400000","o":"7D13BD"},{"b":"400000","o":"5B1BDD"},{"b":"400000","o":"5B33BC"},{"b":"400000","o":"5B38FB"},{"b":"400000","o":"5B62AD"},{"b":"400000","o":"5D8474"},{"b":"400000","o":"5D93FD"},{"b":"400000","o":"5DA10B"},{"b":"400000","o":"79EF5A"},{"b":"400000","o":"6B5290"},{"b":"400000","o":"40FC1D"},{"b":"400000","o":"B115BB"},{"b":"7F5160526000","o":"7DF5"},{"b":"7F515EEE6000","o":"F61AD"}],"processInfo":{ "mongodbVersion" : "3.0.4", "gitVersion" : "0481c958daeb2969800511e7475dc66986fa9ed5", "uname" : { "sysname" : "Linux", "release" : "3.10.0-229.4.2.el7.x86_64", "version" : "#1 SMP Wed May 13 10:06:09 UTC 2015", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "69E53C6FFEE320204F7099893CA3B40309400897" }, { "b" : "7FFF2B8FE000", "elfType" : 3, "buildId" : "F28A1A21A26AA1DF7B5706613BA5F59BB6A28FF0" }, { "b" : "7F5160526000", "path" : "/lib64/libpthread.so.0", "elfType" : 3, "buildId" : "12F30315D4F4A2FE58B1977405C8B5515861E66B" }, { "b" : "7F51602B9000", "path" : "/lib64/libssl.so.10", "elfType" : 3, "buildId" : "8F0FF221DBC5B1A9B130D4D8A19E5C84CC6A6F0F" }, { "b" : "7F515FED2000", "path" : "/lib64/libcrypto.so.10", "elfType" : 3, "buildId" : "688580EF82EF293C98600A46ED38F1453024C966" }, { "b" : "7F515FCCA000", "path" : "/lib64/librt.so.1", "elfType" : 3, "buildId" : "7376A07360DC57189A8F92B20AA4AA1CAEA80551" }, { "b" : "7F515FAC6000", "path" : "/lib64/libdl.so.2", "elfType" : 3, "buildId" : "4DFEE4EA9AE8FDD4C71BD4CCC0727222F19DF810" }, { "b" : "7F515F7BF000", "path" : "/lib64/libstdc++.so.6", "elfType" : 3, "buildId" : "405EACD649720B8668FFBBA197CBF030A7EF6296" }, { "b" : "7F515F4BD000", "path" : "/lib64/libm.so.6", "elfType" : 3, "buildId" : "A1AA62B29765BE03A36BF927B047EEEF8696EEC6" }, { "b" : "7F515F2A7000", "path" : "/lib64/libgcc_s.so.1", "elfType" : 3, "buildId" : "5D3D7256AE68BCFF41E312A24825ED80ECA88A73" }, { "b" : "7F515EEE6000", "path" : "/lib64/libc.so.6", "elfType" : 3, "buildId" : "C31FFE7942BFD77B2FCA8F9BD5709D387A86D3BC" }, { "b" : "7F5160742000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "9866E1D2BA61EBB4CE4F009FACDAACC24EF3B804" }, { "b" : "7F515EC9A000", "path" : "/lib64/libgssapi_krb5.so.2", "elfType" : 3, "buildId" : "34672D541C8C9C5C1C25CB4F3F332CC9D3E604AD" }, { "b" : "7F515E9B7000", "path" : "/lib64/libkrb5.so.3", "elfType" : 3, "buildId" : "45CB7F6CD322F5B55FF8B635F7EC1578631CCAEA" }, { "b" : "7F515E7B3000", "path" : "/lib64/libcom_err.so.2", "elfType" : 3, "buildId" : "3A1166709F88740C49E060731832E3FAD2DFB66B" }, { "b" : "7F515E581000", "path" : "/lib64/libk5crypto.so.3", "elfType" : 3, "buildId" : "23A2D854538903E2B84EF0882046DD95522C8B59" }, { "b" : "7F515E36B000", "path" : "/lib64/libz.so.1", "elfType" : 3, "buildId" : "E45643F27F3B3E960F3691AFC6EC27A98EF7B46B" }, { "b" : "7F515E15C000", "path" : "/lib64/libkrb5support.so.0", "elfType" : 3, "buildId" : "F4A3D5E7E23F871751CA8F250421F8CF83447AD2" }, { "b" : "7F515DF58000", "path" : "/lib64/libkeyutils.so.1", "elfType" : 3, "buildId" : "2E01D5AC08C1280D013AAB96B292AC58BC30A263" }, { "b" : "7F515DD3E000", "path" : "/lib64/libresolv.so.2", "elfType" : 3, "buildId" : "AC596E865AF0D14B10F7B707F47D2031AD6D68DC" }, { "b" : "7F515DB19000", "path" : "/lib64/libselinux.so.1", "elfType" : 3, "buildId" : "82FF6B18E1E42825CC2D060F969479AD4AF2F62C" }, { "b" : "7F515D8B8000", "path" : "/lib64/libpcre.so.1", "elfType" : 3, "buildId" : "298B19C64B19995F2AA4DA7B852E90BA5302F630" }, { "b" : "7F515D693000", "path" : "/lib64/liblzma.so.5", "elfType" : 3, "buildId" : "218D03D1F6CF1A099A4D467B5E8ECF4F2BF45750" } ] }}
 mongod(_ZN5mongo15printStackTraceERSo+0x29) [0xf5e489]
 mongod(_ZN5mongo10logContextEPKc+0xE1) [0xefd4b1]
 mongod(_ZN5mongo17invariantOKFailedEPKcRKNS_6StatusES1_j+0xDA) [0xee3afa]
 mongod(_ZN5mongo17WiredTigerSessionC1EP15__wt_connectionii+0xA0) [0xd81160]
 mongod(_ZN5mongo22WiredTigerSessionCache10getSessionEv+0x4C6) [0xd81636]
 mongod(_ZN5mongo22WiredTigerRecoveryUnit10getSessionEPNS_16OperationContextE+0x3E) [0xd7cade]
 mongod(_ZN5mongo16WiredTigerCursorC1ERKSsmbPNS_16OperationContextE+0x35) [0xd7cb25]
 mongod(_ZNK5mongo21WiredTigerIndexUnique9newCursorEPNS_16OperationContextEi+0x55) [0xd6b415]
 mongod(_ZNK5mongo22BtreeBasedAccessMethod10findSingleEPNS_16OperationContextERKNS_7BSONObjE+0x25) [0xa84d25]
 mongod(_ZN5mongo11IDHackStage4workEPm+0xD0) [0xa0de30]
 mongod(_ZN5mongo11UpdateStage4workEPm+0x7C) [0xa39e0c]
 mongod(_ZN5mongo12PlanExecutor18getNextSnapshottedEPNS_11SnapshottedINS_7BSONObjEEEPNS_8RecordIdE+0xA4) [0xbd09a4]
 mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_8RecordIdE+0x34) [0xbd0d54]
 mongod(_ZN5mongo12PlanExecutor11executePlanEv+0x3D) [0xbd13bd]
 mongod(_ZN5mongo18WriteBatchExecutor10execUpdateERKNS_12BatchItemRefEPNS_7BSONObjEPPNS_16WriteErrorDetailE+0x71D) [0x9b1bdd]
 mongod(_ZN5mongo18WriteBatchExecutor11bulkExecuteERKNS_21BatchedCommandRequestERKNS_19WriteConcernOptionsEPSt6vectorIPNS_19BatchedUpsertDetailESaIS9_EEPS7_IPNS_16WriteErrorDetailESaISE_EE+0x23C) [0x9b33bc]
 mongod(_ZN5mongo18WriteBatchExecutor12executeBatchERKNS_21BatchedCommandRequestEPNS_22BatchedCommandResponseE+0x37B) [0x9b38fb]
 mongod(_ZN5mongo8WriteCmd3runEPNS_16OperationContextERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x15D) [0x9b62ad]
 mongod(_ZN5mongo12_execCommandEPNS_16OperationContextEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x34) [0x9d8474]
 mongod(_ZN5mongo7Command11execCommandEPNS_16OperationContextEPS0_iPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0xC1D) [0x9d93fd]
 mongod(_ZN5mongo12_runCommandsEPNS_16OperationContextEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x28B) [0x9da10b]
 mongod(_ZN5mongo8runQueryEPNS_16OperationContextERNS_7MessageERNS_12QueryMessageERKNS_15NamespaceStringERNS_5CurOpES3_+0x77A) [0xb9ef5a]
 mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xB10) [0xab5290]
 mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xDD) [0x80fc1d]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x34B) [0xf115bb]
 libpthread.so.0(+0x7DF5) [0x7f516052ddf5]
 libc.so.6(clone+0x6D) [0x7f515efdc1ad]
-----  END BACKTRACE  -----
2015-06-20T08:31:32.419+0700 I -        [conn40] 
 
***aborting after invariant() failure



 Comments   
Comment by THUAN [ 23/Jun/15 ]

I tried to setting a longer timeout

Thanks,

Comment by Ramon Fernandez Marina [ 22/Jun/15 ]

tieutinh189, please note that setting a very low value for cursor timeout may impact your application. Please see this comment for more information.

Thanks,
Ramón.

Comment by Ramon Fernandez Marina [ 21/Jun/15 ]

Thanks for getting back to us tieutinh189, and glad to hear the workaround worked for you. This behavior was reported in SERVER-17364, so I'm going to mark this ticket as a duplicate. Feel free to watch SERVER-17364 for updates.

Regards,
Ramón.

Comment by THUAN [ 21/Jun/15 ]

I have try setting, now, no longer occurred.
Thank you for your support

Comment by Ramon Fernandez Marina [ 20/Jun/15 ]

Thanks for additional information tieutinh189. The line

2015-06-20T08:31:32.408+0700 E STORAGE  [conn40] WiredTiger (12) [1434763892:408515][27568:0x7f514db39700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory

indicates you're hitting the 20k session limit, which can be achieved by not properly closing cursors. If you're using the Node.js driver you may want to check NODE-487 for more information.

Are you using the Node.js driver? Can you please try setting a low value for idle cursors timeout and try your insert workload again? SERVER-8188 describes how to do this:

use admin
db.runCommand({setParameter:1, cursorTimeoutMillis: 5000})

Thanks,
Ramón.

Comment by Daniel Pasette (Inactive) [ 20/Jun/15 ]

looks like a duplicate of SERVER-17364

Comment by THUAN [ 20/Jun/15 ]

Log startup

2015-06-20T20:29:03.087+0700 I CONTROL ***** SERVER RESTARTED *****
2015-06-20T20:29:03.120+0700 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=62G,session_max=20000,eviction=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2015-06-20T20:29:03.260+0700 I STORAGE [initandlisten] Starting WiredTigerRecordStoreThread local.oplog.$main
2015-06-20T20:29:03.493+0700 I CONTROL [initandlisten] MongoDB starting : pid=8692 port=27017 dbpath=/home/data/new master=1 64-bit host=(changed)
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** WARNING: You are running on a NUMA machine.
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** We suggest launching mongod like this to avoid performance problems:
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** numactl --interleave=all mongod [other options]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] ** WARNING: soft rlimits too low. rlimits set to 4096 processes, 64000 files. Number of processes should be at least 32000 : 0.5 times number of files.
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten]
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] db version v3.0.4
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] git version: 0481c958daeb2969800511e7475dc66986fa9ed5
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.0.1e-fips 11 Feb 2013
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] build info: Linux ip-10-169-82-254 3.10.0-121.el7.x86_64 #1 SMP Tue Apr 8 10:48:19 EDT 2014 x86_64 BOOST_LIB_VERSION=1_49
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] allocator: tcmalloc
2015-06-20T20:29:03.495+0700 I CONTROL [initandlisten] options: { config: "/etc/mongod.conf", master: true, net:

{ port: 27017 }

, operationProfiling:

{ mode: "slowOp", slowOpThresholdMs: 100 }

, processManagement:

{ fork: true, pidFilePath: "/var/run/mongodb/mongod.pid" }

, security:

{ authorization: "enabled", keyFile: "/var/key/mongodb_key" }

, storage:

{ dbPath: "/home/data/new", directoryPerDB: true, engine: "wiredTiger" }

, systemLog:

{ destination: "file", logAppend: true, path: "/home/logs/mongodb/mongod.log" }

}

Thank you

Comment by Ramon Fernandez Marina [ 20/Jun/15 ]

tieutinh189, as per the error in the log MongoDB is not able to allocate memory. Can you please send us:

  1. The first lines of the log files where startup options are listed
  2. The amount of memory and swap installed on you system

to further diagnose this issue?

Thanks,
Ramón.

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