Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-17334

Runs out of sessions on capped collection during load test (WT, not MMAP)

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Critical - P2 Critical - P2
    • None
    • Affects Version/s: 3.0.0-rc8
    • Component/s: WiredTiger
    • None
    • Environment:
      osx 10.10 yosemite, mongodb-rc8 and mongodb-rc9 (master)
    • Fully Compatible
    • ALL
    • Hide

      2 processes with 50 connections each generate 1000 inserts a second into a capped collection while there is 2 processes that continuously query the capped collection using tailed cursors and closing after the first document is received.

      After a while the server exits with not able to allocate memory

      I'll be happy to help anyone who wants to reproduce the issue (tested against RC8 and current master)

      Reproduce steps

      1. Install node.js 0.12.0 or 0.10.0
2. git clone https://github.com/christkv/learnmongodbthehardway
3. cd learnmongodbthehardway
4. npm install
5. start mongod running on 27017 with wired tiger
6. node runner.js -s ./simulations/topic_simulation.js -n 2

      Wait for mongod process to fail

      Show
      2 processes with 50 connections each generate 1000 inserts a second into a capped collection while there is 2 processes that continuously query the capped collection using tailed cursors and closing after the first document is received. After a while the server exits with not able to allocate memory I'll be happy to help anyone who wants to reproduce the issue (tested against RC8 and current master) Reproduce steps 1. Install node.js 0.12.0 or 0.10.0 2. git clone https: //github.com/christkv/learnmongodbthehardway 3. cd learnmongodbthehardway 4. npm install 5. start mongod running on 27017 with wired tiger 6. node runner.js -s ./simulations/topic_simulation.js -n 2 Wait for mongod process to fail 

      Christians-MacBook-Pro:learnmongodbthehardway christkv$ rm -rf data/;mkdir data;mongod --dbpath=./data --storageEngine=wiredTiger
2015-02-20T15:37:45.178+0100 I CONTROL  [initandlisten] MongoDB starting : pid=5192 port=27017 dbpath=./data 64-bit host=Christians-MacBook-Pro.local
2015-02-20T15:37:45.178+0100 I CONTROL  [initandlisten] db version v3.0.0-rc8
2015-02-20T15:37:45.178+0100 I CONTROL  [initandlisten] git version: 9d0714cdcffadb203ff68730acedbc40875403da
2015-02-20T15:37:45.178+0100 I CONTROL  [initandlisten] build info: Darwin mci-osx108.build.10gen.cc 12.3.0 Darwin Kernel Version 12.3.0: Sun Jan  6 22:37:10 PST 2013; root:xnu-2050.22.13~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49
2015-02-20T15:37:45.178+0100 I CONTROL  [initandlisten] allocator: system
2015-02-20T15:37:45.179+0100 I CONTROL  [initandlisten] options: { storage: { dbPath: "./data", engine: "wiredTiger" } }
2015-02-20T15:37:45.179+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=8G,session_max=20000,eviction=(threads_max=4),statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),
2015-02-20T15:37:45.574+0100 I NETWORK  [initandlisten] waiting for connections on port 27017
2015-02-20T15:37:48.233+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62870 #1 (1 connection now open)
2015-02-20T15:37:48.240+0100 I NETWORK  [conn1] end connection 127.0.0.1:62870 (0 connections now open)
2015-02-20T15:37:48.348+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62871 #2 (1 connection now open)
2015-02-20T15:37:48.587+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62874 #3 (2 connections now open)
2015-02-20T15:37:48.589+0100 I NETWORK  [conn3] end connection 127.0.0.1:62874 (1 connection now open)
2015-02-20T15:37:48.698+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62875 #4 (2 connections now open)
2015-02-20T15:37:48.809+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62876 #5 (3 connections now open)
2015-02-20T15:37:48.809+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62877 #6 (4 connections now open)
2015-02-20T15:37:48.810+0100 I NETWORK  [conn5] end connection 127.0.0.1:62876 (3 connections now open)
2015-02-20T15:37:48.814+0100 I NETWORK  [conn6] end connection 127.0.0.1:62877 (2 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62878 #7 (3 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62879 #8 (4 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62880 #9 (5 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62881 #10 (6 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62882 #11 (7 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62883 #12 (8 connections now open)
2015-02-20T15:37:48.922+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62884 #13 (9 connections now open)
2015-02-20T15:37:48.923+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62885 #14 (10 connections now open)
2015-02-20T15:37:48.923+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62886 #15 (11 connections now open)
2015-02-20T15:37:48.923+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62887 #16 (12 connections now open)
2015-02-20T15:37:49.123+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62890 #17 (13 connections now open)
2015-02-20T15:37:49.124+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62891 #18 (14 connections now open)
2015-02-20T15:37:49.124+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62892 #19 (15 connections now open)
2015-02-20T15:37:49.127+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62893 #20 (16 connections now open)
2015-02-20T15:37:49.130+0100 I NETWORK  [conn17] end connection 127.0.0.1:62890 (15 connections now open)
2015-02-20T15:37:49.130+0100 I NETWORK  [conn18] end connection 127.0.0.1:62891 (15 connections now open)
2015-02-20T15:37:49.144+0100 I NETWORK  [conn19] end connection 127.0.0.1:62892 (13 connections now open)
2015-02-20T15:37:49.146+0100 I NETWORK  [conn20] end connection 127.0.0.1:62893 (12 connections now open)
2015-02-20T15:37:49.247+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62894 #21 (13 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62895 #22 (14 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62896 #23 (15 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62897 #24 (16 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62898 #25 (17 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62899 #26 (18 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62900 #27 (19 connections now open)
2015-02-20T15:37:49.248+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62901 #28 (20 connections now open)
2015-02-20T15:37:49.249+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62902 #29 (21 connections now open)
2015-02-20T15:37:49.249+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62903 #30 (22 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62904 #31 (23 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62905 #32 (24 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62906 #33 (25 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62907 #34 (26 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62908 #35 (27 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62909 #36 (28 connections now open)
2015-02-20T15:37:49.252+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62910 #37 (29 connections now open)
2015-02-20T15:37:49.253+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62911 #38 (30 connections now open)
2015-02-20T15:37:49.253+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62912 #39 (31 connections now open)
2015-02-20T15:37:49.253+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:62913 #40 (32 connections now open)
2015-02-20T15:40:37.063+0100 E STORAGE  [conn32] WiredTiger (12) [1424443237:63024][5192:0x11105f000], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-02-20T15:40:37.063+0100 I -        [conn32] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-02-20T15:40:37.067+0100 I CONTROL  [conn32]
 0x10d713419 0x10d6c7780 0x10d6b4d05 0x10d5467a9 0x10d54749d 0x10d5455bf 0x10d541651 0x10d53f45c 0x10d1bffd8 0x10d3a2960 0x10d3a2829 0x10d370345 0x10d272380 0x10cfbebe1 0x10d6d723c 0x10d746c11 0x7fff979f32fc 0x7fff979f3279 0x7fff979f14b1
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"10CFB3000","o":"760419"},{"b":"10CFB3000","o":"714780"},{"b":"10CFB3000","o":"701D05"},{"b":"10CFB3000","o":"5937A9"},{"b":"10CFB3000","o":"59449D"},{"b":"10CFB3000","o":"5925BF"},{"b":"10CFB3000","o":"58E651"},{"b":"10CFB3000","o":"58C45C"},{"b":"10CFB3000","o":"20CFD8"},{"b":"10CFB3000","o":"3EF960"},{"b":"10CFB3000","o":"3EF829"},{"b":"10CFB3000","o":"3BD345"},{"b":"10CFB3000","o":"2BF380"},{"b":"10CFB3000","o":"BBE1"},{"b":"10CFB3000","o":"72423C"},{"b":"10CFB3000","o":"793C11"},{"b":"7FFF979F0000","o":"32FC"},{"b":"7FFF979F0000","o":"3279"},{"b":"7FFF979F0000","o":"14B1"}],"processInfo":{ "mongodbVersion" : "3.0.0-rc8", "gitVersion" : "9d0714cdcffadb203ff68730acedbc40875403da", "uname" : { "sysname" : "Darwin", "release" : "14.0.0", "version" : "Darwin Kernel Version 14.0.0: Fri Sep 19 00:26:44 PDT 2014; root:xnu-2782.1.97~2/RELEASE_X86_64", "machine" : "x86_64" }, "somap" : [ { "path" : "/usr/local/bin/mongod", "machType" : 2, "b" : "10CFB3000", "buildId" : "2013B41331753B3BBB5013C9937BBC6B" }, { "path" : "/usr/lib/libSystem.B.dylib", "machType" : 6, "b" : "7FFF93474000", "buildId" : "DA954461EC6A3DF085516FC810627627" }, { "path" : "/usr/lib/libc++.1.dylib", "machType" : 6, "b" : "7FFF8E382000", "buildId" : "1B9530FD989B3174BB1CBDC159501710" }, { "path" : "/usr/lib/system/libcache.dylib", "machType" : 6, "b" : "7FFF8DC29000", "buildId" : "45E9A2E799C436B2BEE30C4E11614AD1" }, { "path" : "/usr/lib/system/libcommonCrypto.dylib", "machType" : 6, "b" : "7FFF94CBE000", "buildId" : "D381EBC669D831D380845A80A32CB748" }, { "path" : "/usr/lib/system/libcompiler_rt.dylib", "machType" : 6, "b" : "7FFF96E37000", "buildId" : "BF8FC133EE103DA69B9092039E28678F" }, { "path" : "/usr/lib/system/libcopyfile.dylib", "machType" : 6, "b" : "7FFF95386000", "buildId" : "0C68D3A6ACDD3EF3991ACC82C32AB836" }, { "path" : "/usr/lib/system/libcorecrypto.dylib", "machType" : 6, "b" : "7FFF993CF000", "buildId" : "E178980139853949B7366B3378873301" }, { "path" : "/usr/lib/system/libdispatch.dylib", "machType" : 6, "b" : "7FFF94ACC000", "buildId" : "502CF32B669B3709886208188225E4F0" }, { "path" : "/usr/lib/system/libdyld.dylib", "machType" : 6, "b" : "7FFF993CB000", "buildId" : "19FAF435C16533749DEFD7BBA7D61DB6" }, { "path" : "/usr/lib/system/libkeymgr.dylib", "machType" : 6, "b" : "7FFF98F6E000", "buildId" : "77845842DE703CC5BD01C3D14227CED5" }, { "path" : "/usr/lib/system/liblaunch.dylib", "machType" : 6, "b" : "7FFF958B9000", "buildId" : "8A9889248BE735FEBF7D322E90EFE49E" }, { "path" : "/usr/lib/system/libmacho.dylib", "machType" : 6, "b" : "7FFF8E013000", "buildId" : "126CA2EDDE91308F8881B9DAEC3C63B6" }, { "path" : "/usr/lib/system/libquarantine.dylib", "machType" : 6, "b" : "7FFF8DF8D000", "buildId" : "DC0416272D92361CBABFA869A5C72293" }, { "path" : "/usr/lib/system/libremovefile.dylib", "machType" : 6, "b" : "7FFF9A85A000", "buildId" : "3485B5F46CE83C628DFD8736ED6E8531" }, { "path" : "/usr/lib/system/libsystem_asl.dylib", "machType" : 6, "b" : "7FFF8D2DF000", "buildId" : "F153AC5B0542356E88C820A62CA704E2" }, { "path" : "/usr/lib/system/libsystem_blocks.dylib", "machType" : 6, "b" : "7FFF985A5000", "buildId" : "9615D10AFCA73BE4AA1A1B195DACE1A1" }, { "path" : "/usr/lib/system/libsystem_c.dylib", "machType" : 6, "b" : "7FFF96016000", "buildId" : "C185E86274243210B5286B822577A4B8" }, { "path" : "/usr/lib/system/libsystem_configuration.dylib", "machType" : 6, "b" : "7FFF8E06F000", "buildId" : "9FBA1CE497D0347EA44393ED94512E92" }, { "path" : "/usr/lib/system/libsystem_coreservices.dylib", "machType" : 6, "b" : "7FFF932FE000", "buildId" : "41B7C5785A5331C8A96FC73E030B0938" }, { "path" : "/usr/lib/system/libsystem_coretls.dylib", "machType" : 6, "b" : "7FFF965F3000", "buildId" : "EBBF7EF680D83F8F825CB412BD6D22C0" }, { "path" : "/usr/lib/system/libsystem_dnssd.dylib", "machType" : 6, "b" : "7FFF976C9000", "buildId" : "62B70ECAE40D3C63896E7F00EC386DDB" }, { "path" : "/usr/lib/system/libsystem_info.dylib", "machType" : 6, "b" : "7FFF91F9E000", "buildId" : "B85A85D585303A93B0C34DEC41F79478" }, { "path" : "/usr/lib/system/libsystem_kernel.dylib", "machType" : 6, "b" : "7FFF9A88F000", "buildId" : "93E0E0A975B63904BB4E4BC7C05F4B6B" }, { "path" : "/usr/lib/system/libsystem_m.dylib", "machType" : 6, "b" : "7FFF97E96000", "buildId" : "1E12AB456D9636D0A226F24D9FB0D9D6" }, { "path" : "/usr/lib/system/libsystem_malloc.dylib", "machType" : 6, "b" : "7FFF9A8B1000", "buildId" : "19BCC25757173502A71F95D65AFA861B" }, { "path" : "/usr/lib/system/libsystem_network.dylib", "machType" : 6, "b" : "7FFF960A5000", "buildId" : "C0B2313D47BE38A9BEE62634A4F5E14B" }, { "path" : "/usr/lib/system/libsystem_networkextension.dylib", "machType" : 6, "b" : "7FFF92000000", "buildId" : "29AB225BD7FB30ED960065D44B9A9442" }, { "path" : "/usr/lib/system/libsystem_notify.dylib", "machType" : 6, "b" : "7FFF8C0BE000", "buildId" : "61147800F3203DAA850CBADF33855F29" }, { "path" : "/usr/lib/system/libsystem_platform.dylib", "machType" : 6, "b" : "7FFF9847F000", "buildId" : "64E34079D7123D669CE2418624A5C040" }, { "path" : "/usr/lib/system/libsystem_pthread.dylib", "machType" : 6, "b" : "7FFF979F0000", "buildId" : "26B1897F0CD330F3B55A37CB45062D73" }, { "path" : "/usr/lib/system/libsystem_sandbox.dylib", "machType" : 6, "b" : "7FFF8B80F000", "buildId" : "DB9962EF889831CC9B87E01F8CE74C9D" }, { "path" : "/usr/lib/system/libsystem_secinit.dylib", "machType" : 6, "b" : "7FFF96E48000", "buildId" : "581DAD0F6B633A48B63B917AF799ABAA" }, { "path" : "/usr/lib/system/libsystem_stats.dylib", "machType" : 6, "b" : "7FFF95C91000", "buildId" : "1DB0443659743F1686CC5FF5F390339C" }, { "path" : "/usr/lib/system/libsystem_trace.dylib", "machType" : 6, "b" : "7FFF96E3F000", "buildId" : "A9E6B7D8C3273742AC5486C94218B1DF" }, { "path" : "/usr/lib/system/libunc.dylib", "machType" : 6, "b" : "7FFF8FD0E000", "buildId" : "5676F7EAC1DF329FB006D2C3022B7D70" }, { "path" : "/usr/lib/system/libunwind.dylib", "machType" : 6, "b" : "7FFF9538F000", "buildId" : "BE7E51A0B6EA3A549CCA9D88F683A6D6" }, { "path" : "/usr/lib/system/libxpc.dylib", "machType" : 6, "b" : "7FFF90123000", "buildId" : "9437C02EA07B38C891CB299FAA63083D" }, { "path" : "/usr/lib/libobjc.A.dylib", "machType" : 6, "b" : "7FFF8DD74000", "buildId" : "3B60CD9074A23A5D9686B0772159792A" }, { "path" : "/usr/lib/libauto.dylib", "machType" : 6, "b" : "7FFF97E4F000", "buildId" : "A260789BD4D8316A9490254767B8A5F1" }, { "path" : "/usr/lib/libc++abi.dylib", "machType" : 6, "b" : "7FFF8CD8F000", "buildId" : "88A22A0F87C63002BFBAAC0F2808B8B9" }, { "path" : "/usr/lib/libDiagnosticMessagesClient.dylib", "machType" : 6, "b" : "7FFF8DF5A000", "buildId" : "2EE8E4365CDC34C599595BA218D507FB" } ] }}
 mongod(_ZN5mongo15printStackTraceERNSt3__113basic_ostreamIcNS0_11char_traitsIcEEEE+0x39) [0x10d713419]
 mongod(_ZN5mongo10logContextEPKc+0x100) [0x10d6c7780]
 mongod(_ZN5mongo17invariantOKFailedEPKcRKNS_6StatusES1_j+0x175) [0x10d6b4d05]
 mongod(_ZN5mongo17WiredTigerSessionC2EP15__wt_connectionii+0x99) [0x10d5467a9]
 mongod(_ZN5mongo22WiredTigerSessionCache10getSessionEv+0xAD) [0x10d54749d]
 mongod(_ZN5mongo16WiredTigerCursorC2ERKNSt3__112basic_stringIcNS1_11char_traitsIcEENS1_9allocatorIcEEEEybPNS_16OperationContextE+0x4F) [0x10d5455bf]
 mongod(_ZN5mongo21WiredTigerRecordStore8IteratorC2ERKS0_PNS_16OperationContextERKNS_8RecordIdERKNS_20CollectionScanParams9DirectionEb+0x61) [0x10d541651]
 mongod(_ZNK5mongo21WiredTigerRecordStore11getIteratorEPNS_16OperationContextERKNS_8RecordIdERKNS_20CollectionScanParams9DirectionE+0x6C) [0x10d53f45c]
 mongod(_ZN5mongo14CollectionScan4workEPm+0x198) [0x10d1bffd8]
 mongod(_ZN5mongo12PlanExecutor18getNextSnapshottedEPNS_11SnapshottedINS_7BSONObjEEEPNS_8RecordIdE+0xA0) [0x10d3a2960]
 mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_8RecordIdE+0x39) [0x10d3a2829]
 mongod(_ZN5mongo8runQueryEPNS_16OperationContextERNS_7MessageERNS_12QueryMessageERKNS_15NamespaceStringERNS_5CurOpES3_b+0xA35) [0x10d370345]
 mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortEb+0x9F0) [0x10d272380]
 mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xE1) [0x10cfbebe1]
 mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x32C) [0x10d6d723c]
 mongod(_ZN5boost12_GLOBAL__N_112thread_proxyEPv+0xB1) [0x10d746c11]
 libsystem_pthread.dylib(_pthread_body+0x83) [0x7fff979f32fc]
 libsystem_pthread.dylib(_pthread_body+0x0) [0x7fff979f3279]
 libsystem_pthread.dylib(thread_start+0xD) [0x7fff979f14b1]
-----  END BACKTRACE  -----
2015-02-20T15:40:37.068+0100 I -        [conn32]

***aborting after invariant() failure

        1. ss.log.zip
          474 kB
        2. ss.log_v1.zip
          513 kB
        3. output.txt.zip
          0.6 kB
        4. output.txt_v1.zip
          0.6 kB
        5. mongod.log.zip
          43 kB
        6. mongod.log_v1.zip
          2.74 MB
        7. good.png
          good.png
          83 kB
        8. bad.png
          bad.png
          95 kB

            Assignee:
            bruce.lucas@mongodb.com Bruce Lucas (Inactive)
            Reporter:
            christkv Christian Amor Kvalheim
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

              Created:
              Updated:
              Resolved: