このページには次が含まれます。

このドキュメントはタイムアウト設定に関する質問や問題に関するよくある質問にお答えするものです。

探している回答が見つからない場合、他のFAQをご確認いただくか、MongoDB User メーリングリストにご質問を投稿してください。

MongoDBドライバーでソケットタイムアウト設定を行うにはどのようにすれば良いでしょうか？

背景

ソケットタイムアウトは、受信データの継続的なフローを監視するように設計されています。データフローが指定されたタイムアウトの間中断された場合、接続は停止または切断されたものとみなされます。

MongoDB

MongoDB ドライバーでは, ソケットタイムアウトのデフォルト値、初期のバージョンでは30秒だったのが、2012年には0に変更されました。0は、オペレーションシステムのデフォルト値を使用を意味する特別な値で、ほとんどのオペレーションシステムでは無限、もしくは無制限です。

アプリケーション/ドライバーがデフォルトの0socketTimeoutにを設定していなければ、アプリケーションは接続が無効となるまで、TCP/IPのデフォルトのタイムアウトを待つことになります。

プラットフォームのデフォルト

Windowsでは、レジストリ内の TcpMaxDataRetransmissions はデフォルトで5となります。実際には、接続を切る前に約20秒間再送に失敗していることを意味します。

Linux上では、切断された接続を検出するために TCP 再送信が使用されます。バックオフリトライメカニズムはラウンドトリップ時間 (RTT) を追跡し、それを初期タイムアウト値として使用し、再試行のたびに2 倍になります。 tcp_retries2 からは、 15 (デフォルト)を設定されているため、数分で数分のタイムアウトに相当します。

これにより、アプリケーションが新しく選出されたプライマリを認識できなくなり、古いプライマリを待機する場合があります。

テストケース

この設定は次のシナリオで再現可能です。

　1.　3 つの AWS マシン A、B、C を作成します。A はアプリケーションをホストし、B はレプリカセットの 2 つのメンバーをホストし、C はレプリカセットの 3 番目のメンバーをホストします。

　2.　C 上のメンバーがプライマリになるようにしてください。

　3.　socketTimeoutMS使った接続文字列に0をセットします。これもデフォルトです。

import pymongo

client = pymongo.MongoClient("mongodb://B:27017,B:27018,C:27019/?replicaSet=rs0&socketTimeoutMS=0&maxPoolSize=1")

coll = client["test"]["coll"]

while True:
    try:
        res = coll.insert_one({})
        print(res)
    except Exception as e:
        print(e)

実行手順

　1.　sudo poweroff -f をPrimaryメンバーのホスト上で使用。

　2.　新しいプライマリが選出された場合でも、アプリケーションが停止し、新しいドキュメントがインサートできなくなる。 (マシン上のインスタンスが未だ停止している場合でも、 mongod インスタンスが再起動されるとすぐにアプリケーションは回復する)

　3.　接続URI上のsocketTimeoutMSの値を他の値(30など)に変更し、そして同じテストを返す。

　4.　アプリケーションはフェイルオーバーで新しいプライマリを選出することが可能。

カーソルが見つからない / カーソルのタイムアウトエラーを解決する方法

課題

アプリケーションログ、もしくは mongodb.log ファイルからCursorNotFound または "Cursor timed out" というメッセージが表記された場合、例として以下のように表示されます。

MongoError: Error on remote shard [shardname:port] :: caused by :: cursor id XXXXX not found

もしくは、

2021-06-05T00:23:38.841+0000 E QUERY [js] Error: getMore command failed: {
"operationTime": Timestamp(1622852618, 50),
  "ok": 0,
  "errmsg": "cursor id xxxxx not found",
  "code": 43,
  "codeName": "CursorNotFound",
  "$clusterTime": {

    "clusterTime": Timestamp(1622852618, 50),
    "signature": {

      "hash": BinData(0, "xxxxx"),
      "keyId": NumberLong("xxxxx")
    }
  }
}

挙動

mongodb.logファイル、またはアプリケーションログで、"Cursor timed out" もしくは "Cursor not found"というエントリが表記される。
"Cursor timed out" というタイムスタンプが、前のタイムスタンプと比べ10分以上遅く出力されている。

原因

複数のドキュメントを返す読み取り操作は、クエリにマッチする全ての値を即座に返すわけではありません。理由は、大量のドキュメントにクエリがマッチする可能性があるためであり、これらの操作はカーソルと呼ばれるオブジェクトに依存します。カーソルは、メモリ消費量とネットワーク帯域幅の使用量を減らす為、バッチ内のドキュメントをフェッチ処理します。

カーソルが"time out"やエラーとなる理由がいくつかあります。

アプリケーションがクエリからのバッチ処理に10分以上かかります

CursorNotFound が出力されるのは、アプリケーションがクエリからのバッチ処理を返すのに10分以上かかっている為に発生するものです。多くの結果を返すクエリは、それぞれ最大 16 MB のバッチでデータを返します。もし次の16MBのバッチにリクエストを投げ10分以上かかっていれば、それはアクティブではない為カーソルはタイムアウトとなり、次のバッチにリクエストが投げられた際CursorNotFoundが返されます。

cursorTimeoutMillisサーバーパラメーターはMongoDBが削除を実行する前に、アイドル状態のカーソルへ閾値(ミリ秒単位)で有効期限を設定します。 cursorTimeoutMillisのデフォルトの値は600000で、つまり10分かかります。アイドル状態のカーソルはバックグランドに ClientCursorMonitorを使ってタイムアウトし、スレッドはmongodログのclientcursormonとして認識できます。

ClientCursorMonitorとアイドル状態のカーソルは、4秒ごとに取得します。(clientCursorMonitorFrequencySecsのデフォルト値)

カーソルのタイムアウトが確認されると、下記のようなログを見ることが可能です。

{"t":{"$date":"2021-12-29T09:22:41.937-05:00"},"s":"I","c":"COMMAND","id":51803,"ctx":"conn3","msg":"Slow query","attr":{"type":"command","ns":"admin.foo","appName":"MongoDB Shell","command":{"find":"foo","filter":{},"batchSize":1,"lsid":{"id":{"$uuid":"824bd767-4a7d-4240-a8cd-8f4c83c8cf99"}},"$db":"admin"},"planSummary":"COLLSCAN","cursorid":4225966264683133400,"keysExamined":0,"docsExamined":1,"numYields":0,"nreturned":1,"reslen":123,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
{"t":{"$date":"2021-12-29T09:22:44.096-05:00"},"s":"I","c":"QUERY","id":20529,"ctx":"clientcursormon","msg":"Cursor timed out","attr":{"cursorId":4225966264683133400,"idleSince":{"$date":"2021-12-29T14:22:41.937Z"}}}
{"t":{"$date":"2021-12-29T09:22:48.031-05:00"},"s":"I","c":"COMMAND","id":51803,"ctx":"conn3","msg":"Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"getMore":4225966264683133400,"collection":"foo","batchSize":1,"lsid":{"id":{"$uuid":"824bd767-4a7d-4240-a8cd-8f4c83c8cf99"}},"$db":"admin"},"cursorid":4225966264683133400,"numYields":0,"ok":0,"errMsg":"cursor id 4225966264683133185 not found","errName":"CursorNotFound","errCode":43,"reslen":129,"locks":{},"protocol":"op_msg","durationMillis":0}}

※ 冗長性のある log messages は増えていきます。

..."s":"I","c":"QUERY","id":20529,"ctx":"clientcursormon","msg":"Cursor timed out..." が含まれている場合、log verbosity(ログの詳細レベル)はデフォルトとなっています。もしこのメッセージが出力された場合、カーソルはcursorTimeoutMillisで設定した以上にアイドル状態が続いたらタイムアウトという結果を出し、以下のようなエラーとして返されます。

Error: command failed: {
    "ok" : 0,
    "errmsg" : "cursor id 4225966264683133185 not found",
    "code" : 43,
    "codeName" : "CursorNotFound"
} with original command request: {
    "getMore" : NumberLong("4225966264683133185"),
    "collection" : "foo",
    "batchSize" : 1,
    "lsid" : {
        "id" : UUID("824bd767-4a7d-4240-a8cd-8f4c83c8cf99")
    }
}

10分以上単一のシャード上でカーソル操作が反復

シャードクラスターでは、単一のシャード上で10分以上もの長い間カーソル操作が繰り返されると、エラーとなります。これはカーソルが別のシャードに確立される前に、アクティブな状態でなかった為タイムアウトとなったのが原因です。 mongosが期限切れのカーソルを持つシャードに移動すると、トリガーが引かれCursorNotFoundが出力されます。

localLogicalSessionTimeoutMinutesを超過

localLogicalSessionTimeoutMinutesのデフォルトの値は30分で、sessionが使用された後、アクティブになる時間 (分単位) を調整します。 Sessionは新しい読み/書き操作をクライアントから受け取らない、あるいは閾値が含まれるrefreshSessionsがリフレッシュされた場合、キャッシュが削除されます。

MongoDB 4.4.8 (SERVER-6036まで) で開始した際、カーソルはsessionの一部として開かれると、ライフタイムはそのsessionに関連づけられる為、sessionを閉じる、または時間切れになると関連するカーソルは終了します。なのでcursorTimeoutMillis/clientcursormonはsession id を持つカーソルのタイムアウトを管理するのに使用しません。

sessionがエラーを取得したことでカーソルがタイムアウトになった場合、以下のようなエラーが出力されます。

{"t":{"$date":"2021-12-29T08:02:04.942-05:00"},"s":"I","c":"COMMAND","id":51803,"ctx":"conn1","msg":"Slow query","attr":{"type":"command","ns":"admin.foo","appName":"MongoDB Shell","command":{"find":"foo","filter":{},"batchSize":1,"lsid":{"id":{"$uuid":"824bd767-4a7d-4240-a8cd-8f4c83c8cf99"}},"$db":"admin"},"planSummary":"COLLSCAN","cursorid":63169428846689080,"keysExamined":0,"docsExamined":1,"numYields":0,"nreturned":1,"reslen":123,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
{"t":{"$date":"2021-12-29T08:03:53.030-05:00"},"s":"I","c":"QUERY","id":20528,"ctx":"LogicalSessionCacheRefresh","msg":"Killing cursor as part of killing session(s)","attr":{"cursorId":63169428846689080}}
{"t":{"$date":"2021-12-29T08:04:04.968-05:00"},"s":"I","c":"COMMAND","id":51803,"ctx":"conn1","msg":"Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"getMore":63169428846689080,"collection":"foo","batchSize":1,"lsid":{"id":{"$uuid":"824bd767-4a7d-4240-a8cd-8f4c83c8cf99"}},"$db":"admin"},"cursorid":63169428846689080,"numYields":0,"ok":0,"errMsg":"cursor id 63169428846689082 not found","errName":"CursorNotFound","errCode":43,"reslen":127,"locks":{},"protocol":"op_msg","durationMillis":0}}

解決策

アプリケーションでの結果のバッチ処理でパフォーマンス向上をさせます。
noCursorTimeout() オプションを使用し、10分間のタイムアウトを無効にします。

※ this noCursorTimeout manual sectionに記載があるように、バッチ間で30分以上アクティブな状態にならなければタイムアウトすることがあります。

cursor.batchSize()の設定サイズを十分に小さくすれば、バッチも小さくなります。この設定は、アプリケーションが一度に処理するドキュメントのバッチを小さくするのに役立ちます。
シャード上の cursor default timeout valu(カーソルのデフォルトのタイムアウト値)を増加させます。これはプロセス全体の設定であり、カーソル保持時間を全体的に長くします。
シャードクラスタの場合、全てのシャードにクエリを均等に振り分けることで、クエリをリファクタリングし、単一のシャードのみにするのを避けましょう。
カーソルを返す操作としては、もしカーソルがlocalLogicalSessionTimeoutMinutes(分単位) で設定した値より長くアイドル状態になる可能性がある場合、 Mongo.startSession()を使用しsessionを明示的にし、 refreshSessionsコマンドを使って定期的にsessionをリフレッシュします。下記例となります。

var session = db.getMongo().startSession()
var sessionId = session.getSessionId().id

var cursor = session.getDatabase("examples").getCollection("data").find().noCursorTimeout()
var refreshTimestamp = new Date() // take note of time at operation start

while (cursor.hasNext()) {

// Check if more than 5 minutes have passed since the last refresh
if ( (new Date() - refreshTimestamp) / 1000 > 300 ) {
    print("refreshing session")
    db.adminCommand({ "refreshSessions" : [sessionId] })
    refreshTimestamp = new Date()
}

// process cursor normally

}

追加資料

alexbevi.com | Troubleshooting MongoDB Cursor xxxxx not found errors

【MongoDB】MongoDB Server FAQ #9: MongoDB タイムアウト設定

MongoDBドライバーでソケットタイムアウト設定を行うにはどのようにすれば良いでしょうか？

背景

MongoDB

プラットフォームのデフォルト

推薦

テストケース

カーソルが見つからない / カーソルのタイムアウトエラーを解決する方法

課題

挙動

原因

アプリケーションがクエリからのバッチ処理に10分以上かかります

10分以上単一のシャード上でカーソル操作が反復

localLogicalSessionTimeoutMinutesを超過

解決策

追加資料

MongoDBドライバーでソケットタイムアウト設定を行うにはどのようにすれば良いでしょうか？

背景

MongoDB

プラットフォームのデフォルト

推薦

テストケース

カーソルが見つからない / カーソルのタイムアウト エラーを解決する方法

課題

挙動

原因

アプリケーションがクエリからのバッチ処理に10分以上かかります

10分以上単一のシャード上でカーソル操作が反復

localLogicalSessionTimeoutMinutesを超過

解決策

追加資料

関連記事

カーソルが見つからない / カーソルのタイムアウトエラーを解決する方法