MongoDB3系でWiredTiger使うなら3.0.6以上で使わないと高負荷時に落ちるので注意マン

どうもどうも乙カレー様です。桑野です。
今日はちょっとだけ神妙な面持ち。

MongoDB3系でWT使っている場合に、3.0.6以前のものを使っていたらバージョンアップしましょうって話。

問題

アクセスの増えてきたタイミングから下記のようなログがでてコネクションが溜まってしまう。
その後溜まりすぎてメモリが確保できずにプロセスが落ちる。死。

2015-08-16T09:06:36.012+0000 E STORAGE [conn38726] WiredTiger (12) [1439715996:12678][61157:0x7f105350e700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-08-16T09:06:36.012+0000 I - [conn38726] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-08-16T09:06:36.013+0000 I NETWORK [initandlisten] connection accepted from 192.168.110.196:20692 #47886 (20559 connections now open)
2015-08-16T09:06:36.013+0000 I NETWORK [initandlisten] connection accepted from 192.168.110.196:20693 #47887 (20560 connections now open)
2015-08-16T09:06:36.014+0000 E STORAGE [conn38650] WiredTiger (12) [1439715996:14701][61157:0x7f105815a700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-08-16T09:06:36.014+0000 I - [conn38650] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-08-16T09:06:36.015+0000 E STORAGE [conn31890] WiredTiger (12) [1439715996:15938][61157:0x7f12003c2700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-08-16T09:06:36.015+0000 I - [conn31890] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-08-16T09:06:36.020+0000 E STORAGE [conn38728] WiredTiger (12) [1439715996:20420][61157:0x7f105330c700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-08-16T09:06:36.020+0000 I - [conn38728] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-08-16T09:06:36.021+0000 E STORAGE [conn1438] WiredTiger (12) [1439715996:21384][61157:0x7f12c63f3700], connection.open_session: only configured to support 20010 sessions (including 10 internal): Cannot allocate memory
2015-08-16T09:06:36.021+0000 I - [conn1438] Invariant failure: ret resulted in status UnknownError 12: Cannot allocate memory at src/mongo/db/storage/wiredtiger/wiredtiger_session_cache.cpp 49
2015-08-16T09:06:36.027+0000 I CONTROL [conn2503]
0xf5e199 0xefd1b1 0xee386a 0xd80e50 0xd81326 0xd7c7ce 0xd7c815 0xd6af65 0xa84a08 0xa0eab2 0xa0f1ed 0xa02e8d 0xa25425 0xa10a64 0xbd06b4 0xbd0a64 0xb9ef64 0xab5040 0x80fbad 0xf112bb 0x7f133d722182 0x7f133c1eb47d
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"400000","o":"B5E199"},{"b":"400000","o":"AFD1B1"},{"b":"400000","o":"AE386A"},{"b":"400000","o":"980E50"},{"b":"400000","o":"981326"},{"b":"400000","o":"97C7CE"},{"b":"400000","o":"97C815"},{"b":"400000","o":"96AF65"},{"b":"400000","o":"684A08"},{"b":"400000","o":"60EAB2"},{"b":"400000","o":"60F1ED"},{"b":"400000","o":"602E8D"},{"b":"400000","o":"625425"},{"b":"400000","o":"610A64"},{"b":"400000","o":"7D06B4"},{"b":"400000","o":"7D0A64"},{"b":"400000","o":"79EF64"},{"b":"400000","o":"6B5040"},{"b":"400000","o":"40FBAD"},{"b":"400000","o":"B112BB"},{"b":"7F133D71A000","o":"8182"},{"b":"7F133C0F1000","o":"FA47D"}],"processInfo":{ "mongodbVersion" : "3.0.4", "gitVersion" : "0481c958daeb2969800511e7475dc66986fa9ed5", "uname" : { "sysname" : "Linux", "release" : "3.13.0-46-generic", "version" : "#77-Ubuntu SMP Mon Mar 2 18:23:39 UTC 2015", "machine" : "x86_64" }, "somap" : [ { "elfType" : 2, "b" : "400000", "buildId" : "32DC52072DB9385642CCB4D2AD2ACDA6E0B87A27" }, { "b" : "7FFFE2AB1000", "elfType" : 3, "buildId" : "88E7559031E488BC215236F4181BD1FAF9A458F0" }, { "b" : "7F133D71A000", "path" : "/lib/x86_64-linux-gnu/libpthread.so.0", "elfType" : 3, "buildId" : "9318E8AF0BFBE444731BB0461202EF57F7C39542" }, { "b" : "7F133D4BC000", "path" : "/lib/x86_64-linux-gnu/libssl.so.1.0.0", "elfType" : 3, "buildId" : "FF43D0947510134A8A494063A3C1CF3CEBB27791" }, { "b" : "7F133D0E2000", "path" : "/lib/x86_64-linux-gnu/libcrypto.so.1.0.0", "elfType" : 3, "buildId" : "379F80D2768BA6A21F52781895EE9F47B34A0A85" }, { "b" : "7F133CEDA000", "path" : "/lib/x86_64-linux-gnu/librt.so.1", "elfType" : 3, "buildId" : "92FCF41EFE012D6186E31A59AD05BDBB487769AB" }, { "b" : "7F133CCD6000", "path" : "/lib/x86_64-linux-gnu/libdl.so.2", "elfType" : 3, "buildId" : "C1AE4CB7195D337A77A3C689051DABAA3980CA0C" }, { "b" : "7F133C9D2000", "path" : "/usr/lib/x86_64-linux-gnu/libstdc++.so.6", "elfType" : 3, "buildId" : "19EFDDAB11B3BF5C71570078C59F91CF6592CE9E" }, { "b" : "7F133C6CC000", "path" : "/lib/x86_64-linux-gnu/libm.so.6", "elfType" : 3, "buildId" : "1D76B71E905CB867B27CEF230FCB20F01A3178F5" }, { "b" : "7F133C4B6000", "path" : "/lib/x86_64-linux-gnu/libgcc_s.so.1", "elfType" : 3, "buildId" : "8D0AA71411580EE6C08809695C3984769F25725B" }, { "b" : "7F133C0F1000", "path" : "/lib/x86_64-linux-gnu/libc.so.6", "elfType" : 3, "buildId" : "30C94DC66A1FE95180C3D68D2B89E576D5AE213C" }, { "b" : "7F133D938000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "9F00581AB3C73E3AEA35995A0C50D24D59A01D47" } ] }}
mongod(_ZN5mongo15printStackTraceERSo+0x29) [0xf5e199]
mongod(_ZN5mongo10logContextEPKc+0xE1) [0xefd1b1]
mongod(_ZN5mongo17invariantOKFailedEPKcRKNS_6StatusES1_j+0xDA) [0xee386a]
mongod(_ZN5mongo17WiredTigerSessionC1EP15__wt_connectionii+0xA0) [0xd80e50]
mongod(_ZN5mongo22WiredTigerSessionCache10getSessionEv+0x4C6) [0xd81326]
mongod(_ZN5mongo22WiredTigerRecoveryUnit10getSessionEPNS_16OperationContextE+0x3E) [0xd7c7ce]
mongod(_ZN5mongo16WiredTigerCursorC1ERKSsmbPNS_16OperationContextE+0x35) [0xd7c815]
mongod(_ZNK5mongo23WiredTigerIndexStandard9newCursorEPNS_16OperationContextEi+0x55) [0xd6af65]
mongod(_ZNK5mongo22BtreeBasedAccessMethod9newCursorEPNS_16OperationContextERKNS_13CursorOptionsEPPNS_11IndexCursorE+0x28) [0xa84a08]
mongod(_ZN5mongo9IndexScan13initIndexScanEv+0x62) [0xa0eab2]
mongod(_ZN5mongo9IndexScan4workEPm+0x4D) [0xa0f1ed]
mongod(_ZN5mongo10FetchStage4workEPm+0xCD) [0xa02e8d]
mongod(_ZN5mongo16ShardFilterStage4workEPm+0x55) [0xa25425]
mongod(_ZN5mongo10LimitStage4workEPm+0x54) [0xa10a64]
mongod(_ZN5mongo12PlanExecutor18getNextSnapshottedEPNS_11SnapshottedINS_7BSONObjEEEPNS_8RecordIdE+0xA4) [0xbd06b4]
mongod(_ZN5mongo12PlanExecutor7getNextEPNS_7BSONObjEPNS_8RecordIdE+0x34) [0xbd0a64]
mongod(_ZN5mongo8runQueryEPNS_16OperationContextERNS_7MessageERNS_12QueryMessageERKNS_15NamespaceStringERNS_5CurOpES3_+0xA74) [0xb9ef64]
mongod(_ZN5mongo16assembleResponseEPNS_16OperationContextERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0xB10) [0xab5040]
mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0xDD) [0x80fbad]
mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x34B) [0xf112bb]
libpthread.so.0(+0x8182) [0x7f133d722182]
libc.so.6(clone+0x6D) [0x7f133c1eb47d]
----- END BACKTRACE -----
2015-08-16T09:06:36.027+0000 I CONTROL [conn38518]
0xf5e199 0xefd1b1 0xee386a 0xd80e50 0xd81326 0xd7c7ce 0xd7c815 0xd6af65 0xa84a08 0xa0eab2 0xa0f1ed 0xa02e8d 0xa25425 0xa10a64 0xbd06b4 0xbd0a64 0xb9ef64 0xab5040 0x80fbad 0xf112bb 0x7f133d722182 0x7f133c1eb47d

原因

この あたり のISSUEに上がってる物が原因

対応1：cursorTimeoutを伸ばす

cursorTimeoutを伸ばす事で回避できるよってあったんでこちら入れてみた。

mongo> use admin
mongo> db.runCommand({setParameter:1, cursorTimeoutMillis: 60000})

全く変わらず。

対応2：シャード増やす

一定以上のアクセスが来なければおこらないはずなので、一時的にシャード増やしてみた。

対応は可能だった、一定の効果は（当たり前）だけどコストが(；´∀｀)
まあ一次対応としてはアリ。

対応3：対応後のバージョンに上げる

3.0.6で対応されたから試してみてよって前述のISSUEにあったので満を持してバージョンアップしてみる。
ちなみにMongoDB Cloud Manager（旧MMS）でのバージョンアップは非常に楽チン（ただしMMSには罠がいっぱいあるので癖を覚えるまで辛い）

バージョン上げたタイミングでコネクションが増え続けることもなくなった。
というわけで、新しいのはまだ人柱的な物もよくありますねって話。それもまた楽し。
他の方でも同様の現象で困っている方がいたらバージョンアップ検討しましょう。

バージョンアップ方法はこの辺りが参考になります。

ではでは！

データベース徹底攻略 (WEB+DB PRESS plus)

キャプテン マンゴー 600ml