ログ メッセージ
Overview
MongoDB は、着信接続、実行されたコマンド、発生した問題などのエントリを含む、イベントの実行中のログを通常の操作の一部として保持します。一般的に、ログ メッセージは、問題の診断、デプロイのモニタリング、パフォーマンスの調整に役立ちます。
ログ メッセージを取得するには、次のいずれかの方法を使用できます。
設定されたでログを表示します。
getLog
コマンドを実行します。MongoDB Atlas を通じてログをダウンロードします。詳しくは、「ログのダウンロード」を参照してください。
構造化ログ
mongod
/ mongos
インスタンスはすべてのログ メッセージを構造化された JSON 形式で出力します。 Log entries are written as a series of key-value pairs, where each key indicates a log message field type, such as "severity", and each corresponding value records the associated logging information for that field type, such as "informational". Previously, log entries were output as plaintext.
例
以下に、MongoDB ログファイルに表示される JSON 形式のログ メッセージの例を示します。
{"t":{"$date":"2020-05-01T15:16:17.180+00:00"},"s":"I", "c":"NETWORK", "id":12345, "ctx":"listener", "svc": "R", "msg":"Listening on", "attr":{"address":"127.0.0.1"}}
JSON ログ エントリーは、読みやすくするためにpretty- printすることができます。 以下は、同じログ エントリーのpretty-printed です。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
たとえば、このログ エントリでは、重大度を表すキー s
には、"情報" を表す値 I
があり、コンポーネントを表すキー c
には、この特定のメッセージの原因が "ネットワーク" コンポーネントであることを示す値 NETWORK
があります。さまざまなフィールドの型については、「ログ メッセージのフィールドの型」セクションで詳しく説明します。
キーと値のペアによる構造化されたロギングにより、自動ツールやログ取り込みサービスによる効率的な解析が可能になり、プログラムによるログ メッセージの検索と分析が容易になります。構造化ログ メッセージの分析例については、「構造化ログ メッセージの解析」セクションを参照してください。
注意
mongod
は、ログファイルに書き込みを行えない場合、終了します。mongod
がログファイルに確実に書き込みを行えるようにするには、ログ ボリューム内にディスクの空き領域があり、ログがローテーションされていることを確認します。
JSON ログの出力形式
すべてのログ出力は JSON 形式で送信されます。以下は送信先の例です。
ログファイル
Syslog
stdout(標準出力)ログ出力先
getLog
コマンドによる出力も JSON 形式です。
各ログ エントリの出力は、Relaxed Extended JSON v2.0 仕様に準拠した自己完結型の JSON オブジェクトで、レイアウトとフィールド順序は以下の通りです。
{ "t": <Datetime>, // timestamp "s": <String>, // severity "c": <String>, // component "id": <Integer>, // unique identifier "ctx": <String>, // context "svc": <String>, // service "msg": <String>, // message body "attr": <Object>, // additional attributes (optional) "tags": <Array of strings>, // tags (optional) "truncated": <Object>, // truncation info (if truncated) "size": <Object> // original size of entry (if truncated) }
フィールドの説明
フィールド名 | タイプ | 説明 |
---|---|---|
| 日時 | ISO-8601 形式のログメッセージのタイムスタンプ。の例については、「 タイムスタンプ 」を参照してください。 |
| 文字列 | ログ・メッセージの短い重大度コードです。の例については、「 重大度 」を参照してください。 |
| 文字列 | ログメッセージの完全なコンポーネント string です。の例については、「 コンポーネント 」を参照してください。 |
| 整数 | ログステートメントのユニークな識別子です。例については、「 既知のログIDによるフィルタリング 」を参照してください。 |
| 文字列 | ログ ステートメントを生成したスレッド名 |
| 文字列 | ログ ステートメントが作成されたコンテキストでのサービスの名前。 |
| 文字列 | サーバーまたはドライバーから渡されたログ出力メッセージ。必要に応じて、メッセージはJSON仕様に従って エスケープ されます。 |
| オブジェクト | One or more key-value pairs for additional log attributes. If a log message does not include any additional attributes, the attr object is omitted.Attribute values may be referenced by their key name in the msg message body, depending on the message. If necessary, theattributes are escaped according to the JSON specification. |
| 文字列の配列 | ログ ステートメントに適用可能なタグを表す文字列。たとえば、 |
| オブジェクト | 該当する場合、ログメッセージの切り捨て に関する情報。切り捨てられた 属性がログエントリに少なくとも 1 |
| オブジェクト | ログエントリが 切り捨て られた場合の元のサイズです。切り捨てられた 属性がログエントリに少なくとも 1 |
エスケープ
メッセージ フィールドと属性フィールドは、必要に応じて緩和 拡張 JSON v2.0 の仕様に従って制御文字をエスケープします。
表現された文字 | エスケープ シーケンス |
---|---|
引用符( |
|
Backslash ( |
|
バックスペース( |
|
フォームフィード( |
|
改行( |
|
キャリッジ リターン( |
|
Horizontal tab ( |
|
上記に記載されていない制御文字は \uXXXX
でエスケープされます(XXXX は 16 進数で表された Unicode コードポイントです)。UTF-8 エンコーディングが無効なバイトは、\ufffd
で表される Unicode の置換文字で置き換えられます。
メッセージのエスケープの例は、例のセクションに記載されています。
切り捨て
バージョン7.3で変更。
maxLogSizeKB
で定義された最大サイズ(デフォルト: 10 KB)を超えた属性は切り捨てられます。切り捨てられた属性では、設定された制限を超えるログデータは省略されますが、引き続きエントリを解析可能な状態に保つために、エントリの JSON 形式は保持されます。
たとえば、次の JSON オブジェクトは、切り捨てられていない$in
フィールドの5000要素を含むcommand
属性を表します。
注意
サンプル ログ エントリは、読みやすいように再フォーマットされています。
{ "command": { "find": "mycoll", "filter": { "value1": { "$in": [0, 1, 2, 3, ... 4999] }, "value2": "foo" }, "sort": { "value1": 1 }, "lsid":{"id":{"$uuid":"80a99e49-a850-467b-a26d-aeb2d8b9f42b"}}, "$db": "testdb" } }
この例では、 $in
配列は376番目の要素で切り捨てられています。これは、後続の要素を含む場合、 command
属性のサイズがmaxLogSizeKB
を超えるためです。 command
属性の残りの部分は省略されます。 切り捨てられたログ エントリーは、次の出力のようになります。
{ "t": { "$date": "2021-03-17T20:30:07.212+01:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn9", "msg": "Slow query", "attr": { "command": { "find": "mycoll", "filter": { "value1": { "$in": [ 0, 1, ..., 376 ] // Values in array omitted for brevity } } }, ... // Other attr fields omitted for brevity }, "truncated": { "command": { "truncated": { "filter": { "truncated": { "value1": { "truncated": { "$in": { "truncated": { "377": { "type": "double", "size": 8 } }, "omitted": 4623 } } } }, "omitted": 1 } }, "omitted": 3 } }, "size": { "command": 21692 } }
切り捨てられた属性が 1 つ以上含まれているログエントリには、ネストされたtruncated
オブジェクトが含まれます。これは、ログ エントリ内で切り捨てられた各属性に関して以下の情報を提供します。
切り捨てられた属性
切り捨てのトリガーとなった属性の特定のサブオブジェクト(該当する場合)
切り捨てられたフィールドのデータ
type
切り捨てのトリガーとなる要素の
size
(バイト単位)切り捨てにより各サブオブジェクトの下で
omitted
であった要素の数
また、切り捨てられた属性を含むログエントリの末尾に、追加のsize
フィールドが含まれることがあります。このフィールドは、切り捨てられる前の属性の元のサイズを示しており、この場合は21692
または約22 KB です。 この最後のsize
フィールドは、 truncated
オブジェクトのsize
フィールドと異なる場合にのみ表示されます。つまり、属性のオブジェクト全体のサイズと、切り捨てられたサブオブジェクトのサイズが異なる場合に表示されます。つまり、上記の例では、 に該当します。
パディング
ファイルまたは Syslog のログの送信先に出力する場合、等幅フォントで表示した際の読みやすさを高めるために、重大度、コンテキスト、ID の各フィールドの後にパディングが追加されます。
以下は、このパディングを示す MongoDB ログファイルの抜粋です。
{"t":{"$date":"2020-05-18T20:18:12.724+00:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main", "svc": "R", "msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"} {"t":{"$date":"2020-05-18T20:18:12.734+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main", "svc": "R", "msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2020-05-18T20:18:12.734+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "ctx":"main", "svc": "R", "msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten", "svc": "R", "msg":"MongoDB starting", "attr":{"pid":10111,"port":27001,"dbPath":"/var/lib/mongo","architecture":"64-bit","host":"centos8"}} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten", "svc": "R", "msg":"Build Info", "attr":{"buildInfo":{"version":"4.4.0","gitVersion":"328c35e4b883540675fb4b626c53a08f74e43cf0","openSSLVersion":"OpenSSL 1.1.1c FIPS 28 May 2019","modules":[],"allocator":"tcmalloc","environment":{"distmod":"rhel80","distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2020-05-18T20:18:12.814+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten", "svc": "R", "msg":"Operating System", "attr":{"os":{"name":"CentOS Linux release 8.0.1905 (Core) ","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}
Pretty Printing(整形表示)
MongoDB 構造化ログを使用する場合、サードパーティの jqコマンドライン ユーティリティ はログ エントリーを簡単かつきれいに印刷したり、キーに基づく強力なマッチングとフィルタリングを実行したりできる便利なツールです。
jq
はオープンソースの JSON パーサーで、Linux、Windows、macOS で利用できます。
次のように、jq
を使用してログ エントリーを pretty-print できます。
ログファイル全体をpretty-printする
cat mongod.log | jq 最新のログ エントリーをpretty-printする
cat mongod.log | tail -1 | jq
MongoDB 構造化ログのその他の例については、「構造化ログ メッセージの解析 」セクションを参照してください。
ログ メッセージの送信先設定
MongoDB ログ メッセージは、ファイル、syslog、stdout(標準出力)のいずれかに出力できます。
ログの出力先を設定するには、構成ファイルまたはコマンドラインで以下のいずれかの設定を使用します。
- 構成ファイル
systemLog.destination
オプションで file または syslogを指定
- コマンドライン
ファイルかsyslogのどちらかを指定しない場合、すべてのログ出力が stdout に送信されます。
以下で、ログ設定とオプションの全リストを参照できます。
- 構成ファイル
- コマンドライン
注意
ファイルや syslog のログの保存先を使用していない場合に起こった起動時の致命的なエラーや、ログ設定の誤りに関連するメッセージなど、stderr
(標準エラー)に送信されるエラー メッセージは、ログ出力先の設定の影響を受けず、プレーンテキスト形式で stderr
に出力されます。
ログ メッセージのフィールド タイプ
タイムスタンプ
タイムスタンプ フィールド タイプは、ログに記録されたイベントが発生した正確な日時を示します。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
ファイル または syslog [1] にログを記録する場合、タイムスタンプのデフォルト形式は iso8601-local
です。タイムスタンプの形式を変更するには、--timeStampFormat
ランタイム オプションか、systemLog.timeStampFormat
設定を使用します。
タイムスタンプ フィールドでフィルタリングするログ解析の例については、「日付範囲によるフィルタリング」を参照してください。
注意
ctime
タイムスタンプ形式はサポートされなくなりました。
[1] | syslog にログを記録する場合、タイムスタンプは MongoDB によりメッセージが発行されたときではなく、syslog デーモンによりメッセージが記録されたときに生成されます。そのため、特にシステムの負荷が高い場合に、ログ エントリのタイムスタンプが不正確になることがあります。 |
重大度
重大度フィールド タイプは、ログに記録されたイベントに関する重大度レベルを示します。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
重大度レベルは、「致命的」(最も重大) から「デバッグ」(最も軽微) までの範囲です。
レベル | 説明 |
---|---|
| 致命的 |
| エラー |
| 警告 |
| |
| MongoDBは特定の デバッグ冗長レベル を示します。例、冗長レベルが2 の場合、 MongoDBは 以前のバージョンでは、MongoDB のログメッセージでは、デバッグの冗長レベルにすべて |
さまざまなコンポーネントの冗長レベルを指定して、MongoDB が出力する情報メッセージとデバッグメッセージの量を決定できます。これらのレベルを超える重大度カテゴリは常に表示されます。[2] 冗長レベルを設定するには、「ログの冗長レベルの設定」を参照してください。
コンポーネント
コンポーネント フィールド タイプは、NETWORK や COMMAND など、ログに記録されたイベントが属するカテゴリを示します。
{ "t": { "$date": "2020-05-01T15:16:17.180+00:00" }, "s": "I", "c": "NETWORK", "id": 12345, "ctx": "listener", "svc": "R", "msg": "Listening on", "attr": { "address": "127.0.0.1" } }
各コンポーネントは、独自の冗長フィルターを介して個別に設定できます。使用可能なコンポーネントは次のとおりです。
ACCESS
認証などのアクセス制御に関連するメッセージです。
ACCESS
コンポーネントのログ レベルを指定するには、systemLog.component.accessControl.verbosity
設定を使用します。
COMMAND
データベース コマンドに関連するメッセージです(
count
など)。COMMAND
コンポーネントのログ レベルを指定するには、systemLog.component.command.verbosity
設定を使用します。
CONTROL
初期化などの制御アクティビティに関連するメッセージです。
CONTROL
コンポーネントのログ レベルを指定するには、systemLog.component.control.verbosity
設定を使用します。
ELECTION
レプリカセットの選挙に特に関連するメッセージです。
ELECTION
コンポーネントのログ レベルを指定するには、systemLog.component.replication.election.verbosity
パラメーターを設定します。REPL
は、ELECTION
の親コンポーネントです。systemLog.component.replication.election.verbosity
が設定されていない場合、MongoDB はREPL
の冗長レベルをELECTION
コンポーネントに対して使用します。
FTDC
サーバー統計やステータス メッセージなど、診断データ コレクション メカニズムに関連するメッセージです。
FTDC
コンポーネントのログ レベルを指定するには、systemLog.component.ftdc.verbosity
設定を使用します。
GEO
GeoJSON の形状の検証など、地理空間の形状の解析に関連するメッセージです。
GEO
コンポーネントのログ レベルを指定するには、systemLog.component.geo.verbosity
パラメーターを設定します。
INDEX
インデックスの作成など、インデックス関連の操作に関連するメッセージです。
INDEX
コンポーネントのログ レベルを指定するには、systemLog.component.index.verbosity
パラメーターを設定します。
INITSYNC
最初の同期操作に関連するメッセージです。
INITSYNC
コンポーネントのログ レベルを指定するには、systemLog.component.replication.initialSync.verbosity
パラメーターを設定します。REPL
は、INITSYNC
の親コンポーネントです。systemLog.component.replication.initialSync.verbosity
が設定されていない場合、MongoDB はREPL
の冗長レベルをINITSYNC
コンポーネントに対して使用します。
JOURNAL
ストレージ ジャーナリング アクティビティに特に関連するメッセージです。
JOURNAL
コンポーネントのログ レベルを指定するには、systemLog.component.storage.journal.verbosity
設定を使用します。STORAGE
は、JOURNAL
の親コンポーネントです。systemLog.component.storage.journal.verbosity
が設定されていない場合、MongoDB はSTORAGE
の冗長レベルをJOURNAL
コンポーネントに対して使用します。
NETWORK
接続の受け入れなど、ネットワーク アクティビティに関連するメッセージです。
NETWORK
コンポーネントのログ レベルを指定するには、systemLog.component.network.verbosity
パラメーターを設定します。
QUERY
クエリ プランナーのアクティビティなど、クエリに関連するメッセージです。
QUERY
コンポーネントのログ レベルを指定するには、systemLog.component.query.verbosity
パラメーターを設定します。
QUERYSTATS
$queryStats
操作に関連するメッセージです。QUERYSTATS
コンポーネントのログ レベルを指定するには、systemLog.component.queryStats.verbosity
パラメーターを設定します。
RECOVERY
ストレージの復旧活動に関連するメッセージです。
RECOVERY
コンポーネントのログ レベルを指定するには、systemLog.component.storage.recovery.verbosity
設定を使用します。STORAGE
は、RECOVERY
の親コンポーネントです。systemLog.component.storage.recovery.verbosity
が設定されていない場合、MongoDB はSTORAGE
の冗長レベルをRECOVERY
コンポーネントに対して使用します。
REPL
最初の同期、ハートビート、定常状態のレプリケーション、ロールバックなど、レプリカセットに関連するメッセージです。[2]
REPL
コンポーネントのログ レベルを指定するには、systemLog.component.replication.verbosity
パラメーターを設定します。REPL
は、ELECTION
、INITSYNC
、REPL_HB
、ROLLBACK
コンポーネントの親コンポーネントです。
REPL_HB
レプリカセットのハートビートに特に関連するメッセージです。
REPL_HB
コンポーネントのログ レベルを指定するには、systemLog.component.replication.heartbeats.verbosity
パラメーターを設定します。REPL
は、REPL_HB
の親コンポーネントです。systemLog.component.replication.heartbeats.verbosity
が設定されていない場合、MongoDB はREPL
の冗長レベルをREPL_HB
コンポーネントに対して使用します。
ROLLBACK
ロールバック操作に関連するメッセージです。
ROLLBACK
コンポーネントのログ レベルを指定するには、systemLog.component.replication.rollback.verbosity
パラメーターを設定します。REPL
は、ROLLBACK
の親コンポーネントです。systemLog.component.replication.rollback.verbosity
が設定されていない場合、MongoDB はREPL
の冗長レベルをROLLBACK
コンポーネントに対して使用します。
SHARDING
シャーディング アクティビティに関連するメッセージです
mongos
の起動など)SHARDING
コンポーネントのログ レベルを指定するには、systemLog.component.sharding.verbosity
設定を使用します。
STORAGE
fsync
コマンドに関係するプロセスなど、ストレージ アクティビティに関連するメッセージです。STORAGE
コンポーネントのログ レベルを指定するには、systemLog.component.storage.verbosity
設定を使用します。
TXN
マルチドキュメントトランザクションに関連するメッセージです。
TXN
コンポーネントのログ レベルを指定するには、systemLog.component.transaction.verbosity
設定を使用します。
WRITE
update
コマンドなどの書込み (write) 操作に関連するメッセージです。WRITE
コンポーネントのログ レベルを指定するには、systemLog.component.write.verbosity
設定を使用します。
WT
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンに関連するメッセージです。
WT
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.verbosity
設定を使用します。
WTBACKUP
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンによって実行されるバックアップ操作に関連するメッセージです。
WTBACKUP
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtBackup.verbosity
設定を使用します。
WTCHKPT
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンによって実行されるチェックポイント操作に関連するメッセージです。
WTCHKPT
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtCheckpoint.verbosity
設定を使用します。
WTCMPCT
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンによって実行される圧縮操作に関連するメッセージです。
WTCMPCT
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtCompact.verbosity
設定を使用します。
WTEVICT
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンによって実行されるメモリ解放操作に関連するメッセージです。
WTEVICT
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtEviction.verbosity
設定を使用します。
WTHS
バージョン 5.3 で追加。
WiredTiger ストレージ エンジンの履歴ストアに関連するメッセージです。
WTHS
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtHS.verbosity
設定を使用します。
WTRECOV
バージョン 5.3 で追加。
WiredTiger storage engine によって実行されたリカバリ操作に関連するメッセージ。
WTRECOV
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtRecovery.verbosity
設定を使用します。
WTRTS
バージョン 5.3 で追加。
WiredTiger storage engine によって実行される安定状態へのロールバック(RTS)操作に関連するメッセージ。
WTRTS
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtRTS.verbosity
設定を使用します。
WTSLVG
バージョン 5.3 で追加。
WiredTiger storage engineによって実行されるサルベージ操作に関連するメッセージ。
WTSLVG
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtSalvage.verbosity
設定を使用します。
WTTS
バージョン 5.3 で追加。
WiredTiger storage engineで使用されるタイムスタンプに関連するメッセージ。
WTTS
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtTimestamp.verbosity
設定を使用します。
WTTXN
バージョン 5.3 で追加。
WiredTigerstorage engine によって実行されたトランザクションに関連するメッセージ。
WTTXN
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtTransaction.verbosity
設定を使用します。
WTVRFY
バージョン 5.3 で追加。
WiredTiger storage engine によって実行された検証操作に関連するメッセージ。
WTVRFY
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtVerify.verbosity
設定を使用します。
WTWRTLOG
バージョン 5.3 で追加。
WiredTiger storage engineによって実行されるログ書込み (write) 操作に関連するメッセージ。
WTWRTLOG
コンポーネントのログ レベルを指定するには、systemLog.component.storage.wt.wtWriteLog.verbosity
設定を使用します。
-
名前付きコンポーネントに関連付けられていないメッセージです。名前のないコンポーネントには、
systemLog.verbosity
設定で指定されたデフォルトのログ レベルが適用されます。systemLog.verbosity
設定は、名前付きコンポーネントと名前のないコンポーネント両方のデフォルト設定です。
コンポーネント フィールドでフィルタリングするログ解析の例については、「コンポーネントによるフィルタリング」を参照してください。
クライアント データ
MongoDB ドライバーとクライアント アプリケーション(mongosh
を含む)には、サーバーへの接続時に識別情報を送信する機能があります。接続が確立されると、接続が切断されて再確立されない限り、クライアントは識別情報を再度送信しません。
この識別情報は、ログエントリーの属性フィールドに含まれています。具体的にどのような情報が含まれるかは、クライアントによって異なります。
以下は、mongosh
接続から送信されたクライアント データ ドキュメントを含むサンプル ログ メッセージです。 クライアント データは、属性フィールドのdoc
オブジェクトに含まれています。
{"t":{"$date":"2020-05-20T16:21:31.561+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn202", "svc": "R", "msg":"client metadata", "attr":{"remote":"127.0.0.1:37106","client":"conn202","doc":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"4.4.0"},"os":{"type":"Linux","name":"CentOS Linux release 8.0.1905 (Core) ","architecture":"x86_64","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}}
レプリカセットのセカンダリがプライマリへの接続を開始すると、同様のデータが送信されます。以下は、この接続開始を含むサンプル ログ メッセージです。クライアント データは、属性フィールド内の doc
オブジェクトに含まれています。
{"t":{"$date":"2020-05-20T16:33:40.595+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn214", "svc": "R", "msg":"client metadata", "attr":{"remote":"127.0.0.1:37176","client":"conn214","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.0"},"os":{"type":"Linux","name":"CentOS Linux release 8.0.1905 (Core) ","architecture":"x86_64","version":"Kernel 4.18.0-80.11.2.el8_0.x86_64"}}}}
クライアント データを示す わかりやすい 例 については、「 例 」のセクション を参照してください。
クライアント情報と必須フィールドの説明については、「 MongoDB ハンドシェイク仕様」を参照してください。
冗長レベル
ログの冗長レベルを指定することで、MongoDB が出力するログ メッセージの量を増減できます。冗長レベルは、すべてのコンポーネントに対してまとめて調整することも、特定の名前付きコンポーネントに対して個別に調整することもできます。
冗長度は、重大度カテゴリが情報およびデバッグのログ エントリにのみ影響します。これらのレベルを超える重大度カテゴリは常に表示されます。
冗長レベルの値を高く設定してデバッグや開発用に冗長なログを表示したり、低く設定して検証済みの本番環境でログへの書込みを最小限に抑えたりできます[2]。
現状のログ冗長レベルの表示
現状の冗長レベルを表示するには、db.getLogComponents()
メソッドを使用します。
db.getLogComponents()
出力は次のようになります。
{ "verbosity" : 0, "accessControl" : { "verbosity" : -1 }, "command" : { "verbosity" : -1 }, ... "storage" : { "verbosity" : -1, "recovery" : { "verbosity" : -1 }, "journal" : { "verbosity" : -1 } }, ...
最初のverbosity
エントリはすべてのコンポーネントの親の冗長レベルですが、それに続く accessControl
などの個々の名前付きコンポーネントは、そのコンポーネントの特定の冗長レベルを示し、設定されている場合はその特定のコンポーネントのグローバル冗長レベルを上書きします。
-1
値は、コンポーネントが親の冗長レベルを持っている場合はそれを継承し(上記の recovery
と同様、storage
から継承)、継承しない場合はグローバル冗長レベル(command
と同様)を継承することを示します。冗長レベルの継承関係は、コンポーネント セクションに示されます。
ログの冗長レベルの構成
冗長レベルは、systemLog.verbosity
および systemLog.component.<name>.verbosity
設定、logComponentVerbosity
パラメータ、db.setLogLevel()
メソッドのいずれかを使用して構成できます[2]。
systemLog
冗長設定
すべてのコンポーネントのデフォルトのログ レベルを構成するには、systemLog.verbosity
設定を使用します。特定のコンポーネントのレベルを構成するには、systemLog.component.<name>.verbosity
設定を使用します。
たとえば、次の構成では、systemLog.verbosity
が 1
に、systemLog.component.query.verbosity
が 2
に、systemLog.component.storage.verbosity
が 2
に、systemLog.component.storage.journal.verbosity
が 1
に設定されます。
systemLog: verbosity: 1 component: query: verbosity: 2 storage: verbosity: 2 journal: verbosity: 1
これらの値は、mongod
または mongos
インスタンスの構成ファイルかコマンド ラインで に設定します。
構成で明示的に指定されていないすべてのコンポーネントの冗長レベルは -1
です。つまり、親がある場合は親の冗長レベルを継承し、ない場合はグローバル冗長レベル(systemLog.verbosity
)を使用します。
logComponentVerbosity
Parameter
logComponentVerbosity
パラメーターを設定するには、変更する冗長設定を含むドキュメントを渡します。
たとえば、次の例では、 default verbosity level
を1
に、 query
を2
に、 storage
を2
に、 storage.journal
を1
に設定します。
db.adminCommand( { setParameter: 1, logComponentVerbosity: { verbosity: 1, query: { verbosity: 2 }, storage: { verbosity: 2, journal: { verbosity: 1 } } } } )
値は mongosh
から設定します。
db.setLogLevel()
単一のコンポーネント ログ レベルを更新するには、db.setLogLevel()
メソッドを使用します。コンポーネントには、0
から 5
までの冗長レベルを指定できます。また、親の冗長度を継承するには、-1
を指定します。たとえば、次の例では systemLog.component.query.verbosity
をその親の冗長度(デフォルトの冗長度)に設定しています。
db.setLogLevel(-1, "query")
値は mongosh
から設定します。
[2] | ( 1 、 2 、 3 、 4 、 5 ) replica setのセカンダリ メンバーは、低速操作のしきい値よりも長い時間がかかるエントリをログにoplogするようになりました。 これらの遅い oplog メッセージ:
|
低速操作のログ
クライアント操作(クエリなど)は、処理時間が低速操作しきい値を超えた場合、またはログの冗長レベルが 1 以上の場合にログに表示されます。[2] これらのログエントリには、操作に関連付けられた完全なコマンドオブジェクトが含まれます。
プロファイラー エントリと読み取り操作および書込み (write) 操作の診断ログ メッセージ(mongod/mongos ログ メッセージなど)には次のものが含まれます。
planCacheShapeHash
プランキャッシュクエリシェイプが同じスロークエリを特定するのに役立ちます。MongoDB 8.0以降、既存の
queryHash
フィールドの名前がplanCacheShapeHash
に変更されます。 以前のバージョンの MongoDB を使用している場合は、planCacheShapeHash
ではなくqueryHash
が表示されます。planCacheKey
低速クエリのクエリプラン キャッシュに関する詳細なインサイトを提供します。
MongoDB 5.0 以降では、低速操作ログ メッセージにクライアントの IP アドレスを指定する remote
フィールドが含まれます。
MongoDB 6.2 以降では、低速操作ログ メッセージに、クエリを実行したクエリ エンジンを示す queryFramework
フィールドが含まれます。
queryFramework: "classic"
は、クラシック エンジンでクエリが実行されたことを示します。queryFramework: "sbe"
はスロットベースのクエリ実行エンジンでクエリが実行されたことを示します。
MongoDB 6 . 1 以降では、低速操作のログ メッセージにキャッシュ更新時間フィールドが含まれます。
MongoDB 6.3 以降では、低速操作のログ メッセージとデータベースプロファイラーのエントリに、クエリ操作にかかった合計 CPU 時間をナノ秒単位で指定する cpuNanos
フィールドが含まれます。cpuNanos
フィールドは Linux システムでのみ使用できます。
MongoDB 7.0 (および6.0.13以降) 以降では、 5.0.24 )、低速クエリ ログ メッセージのtotalOplogSlotDurationMicros
は、書込み操作が storage engine の書込み (write) をコミットするためのコミット タイムスタンプを取得してから実際にコミットするまでの時間を示しています。 mongod
は並列書込みをサポートします。 ただし、書込み (write) 操作はコミット タイムスタンプとともに任意の順序でコミットされます。
例
次のコミット タイムスタンプを持つ書込みについて考えてみましょう。
書込み A とタイムスタンプ 1
書込み B とタイムスタンプ 2
書込み C とタイムスタンプ 3
書込み B が タイムスタンプ 2 で最初にコミットするとします。レプリケーションは書込み A がコミットするまで一時停止します。レプリケーションでレプリカセットのセカンダリに oplog をコピーするには、書込み A の oplog エントリとタイムスタンプ 1 が必要なためです。
低速操作のログ エントリのわかりやすい例については、「ログ メッセージの例」を参照してください。
MongoDB 8.0 以降では、クエリシェイプの queryShapeHash
フィールドも、使用可能な場合、スロークエリログに含まれます。
MongoDB 8.0 以降でも、スロークエリの出力には、操作のキューに関する情報を含む queues
ドキュメントが含まれます。queues
フィールドの各キューには、対応するキューで操作が費やした合計累積時間(マイクロ秒単位)を含む totalTimeQueuedMicros
フィールドが含まれています。
フィールドにログインしたシャードの待機時間remoteOpWaitMillis
バージョン 5.0 で追加
MongoDB 5.0 以降では、remoteOpWaitMillis
ログ フィールドを使用して、シャードから結果を受信するまでの待機時間(ミリ秒単位)を取得できます。
remoteOpWaitMillis
は次の場合にのみログに記録されます。
低速クエリの原因がマージ操作かシャードの問題かを判断するには、ログ内の workingMillis
時間フィールドと remoteOpWaitMillis
の時間フィールドを比較します。workingMillis
はクエリが完了するまでにかかった合計時間です。具体的な説明は以下の通りです。
workingMillis
がremoteOpWaitMillis
よりわずかに長い場合、ほとんどの時間はシャード応答の待機に費やされたことになります。たとえば、workingMillis
が 17 で、remoteOpWaitMillis
が 15 の場合が挙げられます。workingMillis
がremoteOpWaitMillis
よりもかなり長い場合、ほとんどの時間はマージを実行することに費やされたことになります。たとえば、workingMillis
が 100 で、remoteOpWaitMillis
が 15 の場合が挙げられます。
ログ リダクション
Queryable Encryption におけるログのリダクション
Queryable Encryption の使用中は、暗号化されたコレクションに対する CRUD 操作は低速クエリのログから省略されます。詳しくは、「Queryable Encryption のリダクション」を参照してください。
Enterprise におけるログのリダクション
MongoDB Enterprise でのみ利用可能
redactClientLogData
を使用して実行中の mongod
または mongos
は、特定のログ イベントに付随するすべてのメッセージを、ログに記録する前にレダクションします。そのため、そのイベントに関連するメタデータ、ソース ファイル、行番号のみがログに記録されます。redactClientLogData
は、診断に役立つ詳細情報を犠牲にして、機密情報の可能性がある情報がシステム ログに入力されるのを防ぎます。
たとえば、次の操作は、ログ リダクションなしで実行されている mongod
にドキュメントを挿入します。mongod
では、ログの冗長レベルは 1
に設定されています。
db.clients.insertOne( { "name" : "Joe", "PII" : "Sensitive Information" } )
この操作により、以下のログ イベントが発生します。
{ "t": { "$date": "2024-07-19T15:36:55.024-07:00" }, "s": "I", "c": "COMMAND", ... "attr": { "type": "command", ... "appName": "mongosh 2.2.10", "command": { "insert": "clients", "documents": [ { "name": "Joe", "PII": "Sensitive Information", "_id": { "$oid": "669aea8792c7fd822d3e1d8c" } } ], "ordered": true, ... } ... } }
ともに実行されている mongod
と redactClientLogData
が、同じ挿入操作を実行すると、次のログ イベントが生成されます。
{ "t": { "$date": "2024-07-19T15:36:55.024-07:00" }, "s": "I", "c": "COMMAND", ... "attr": { "type": "command", ... "appName": "mongosh 2.2.10", "command": { "insert": "###", "documents": [ { "name": "###", "PII": "###", "_id": "###" } ], "ordered": "###", ... } ... } }
規制要件への準拠に、redactClientLogData
をを保存時の暗号化および TLS/SSL(トランスポート暗号化)と組み合わせて使用することが役立ちます。
構造化ログメッセージの解析
ログ解析とは、プログラムによってログファイルを検索し、分析することで、多くの場合自動的に行われます。構造化ログの導入により、ログ解析の難易度が下がり、効果が向上しました。以下は、その例です。
ログ メッセージ フィールドはキーと値のペアとして表示されます。ログ・パーサーは、結果を効率的にフィルタリングするために、特定のキーでクエリを実行できます。
ログメッセージのメッセージ構造は、常に同じです。ログ パーサーは、あらゆるログメッセージから確実に情報を抽出できます。情報が欠落している場合や形式が異なる場合にコーディングが必要になることはありません。
次の例は、MongoDB の JSON ログ出力を扱う際の一般的なログ解析ワークフローです。
ログ解析の例
MongoDB 構造化ログを使用する場合、サードパーティの jqコマンドライン ユーティリティ は、ログ エントリーを簡単かつきれいに印刷したり、キーに基づく強力なマッチングとフィルタリングを実行したりできる便利なツールです。
jq
はオープンソースの JSON パーサーで、Linux、Windows、macOS で利用できます。
これらの例では、ログ解析を簡略化するために jq
を使用しています。
ユニーク メッセージの集計
特定のログファイル内のユニーク メッセージを出現頻度順に上位 10 件表示しています。
jq -r ".msg" /var/log/mongodb/mongod.log | sort | uniq -c | sort -rn | head -10
接続のモニタリング
リモート クライアント接続は、属性オブジェクト内の「remote」キーの下のログに表示されます。次の例では、ログファイル全体のすべてのユニーク接続をカウントし、発生回数を降順に表示しています。
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | sort | uniq -c | sort -r
同じ IP アドレスによる接続でも、異なるポートを経由する接続は、このコマンドでは異なる接続として扱われます。出力を IP アドレスのみを考慮したものに限るには、以下のように変更します。
jq -r '.attr.remote' /var/log/mongodb/mongod.log | grep -v 'null' | awk -F':' '{print $1}' | sort | uniq -c | sort -r
ドライバー接続の分析
次の例では、すべてのリモート MongoDB ドライバー接続をカウントし、発生回数の降順で各ドライバーの種類とバージョンを表示します。
jq -cr '.attr.doc.driver' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
クライアント タイプの分析
次の例では、報告されたリモート MongoDB ドライバー接続とクライアント アプリケーション(mongosh
を含む)のクライアント データを分析し、接続しているユニークなオペレーティング システムの種類ごとに、頻度順で合計を出力します。
jq -r '.attr.doc.os.type' /var/log/mongodb/mongod.log | grep -v null | sort | uniq -c | sort -rn
このログフィールドで報告されている「Darwin」という文字列は、macOS クライアントを示しています。
低速クエリの分析
低速操作のログ記録を有効にすると、次の例では、さらなる分析のために、2000 ミリ秒以上かかった低速操作のみが返されます。
jq 'select(.attr.workingMillis>=2000)' /var/log/mongodb/mongod.log
この例に示されている jq
フィルターの詳細については、「jq ドキュメント」を参照してください。
コンポーネントによるフィルタリング
ログ コンポーネント(JSON ログ出力形式の 3 番目のフィールド)は、特定のログ メッセージが属する一般的なカテゴリを示します。コンポーネントによるフィルタリングは、ログ メッセージを解析して関連するイベントを探す際の出発点として最適です。
次の例では、コンポーネントタイプREPLのログ メッセージのみを出力します。
jq 'select(.c=="REPL")' /var/log/mongodb/mongod.log
次の例では、コンポーネントタイプ REPL 以外のすべてのログ メッセージを出力します。
jq 'select(.c!="REPL")' /var/log/mongodb/mongod.log
次の例では、コンポーネントタイプ REPL またはストレージのログ メッセージを出力します。
jq 'select( .c as $c | ["REPL", "STORAGE"] | index($c) )' /var/log/mongodb/mongod.log
この例に示されている jq
フィルターの詳細については、「jq ドキュメント」を参照してください。
既知のログ ID によるフィルタリング
ログ ID(JSON ログ出力形式の 5 番目のフィールド)は特定のログ イベントにマッピングされ、MongoDB のリリースが変わっても安定した状態が維持されます。
たとえば、次の 2 つのログ イベントは、クライアント接続の後に切断が行われたことを示しています。
{"t":{"$date":"2020-06-01T13:06:59.027-0500"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener", "svc": "R", "msg":"connection accepted from {session_remote} #{session_id} ({connectionCount}{word} now open)", "attr":{"session_remote":"127.0.0.1:61298", "session_id":164,"connectionCount":11,"word":" connections"}} {"t":{"$date":"2020-06-01T13:07:03.490-0500"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn157", "svc": "R", "msg":"end connection {remote} ({connectionCount}{word} now open)", "attr":{"remote":"127.0.0.1:61298","connectionCount":10,"word":" connections"}}
これら 2 つのエントリのログ ID はそれぞれ 22943
と 22944
です。次に、以下の jq
構文を使用してログ出力をフィルタリングしてこれらのログ ID のみを表示することで、実質的にクライアント接続アクティビティのみを表示できます。
jq 'select( .id as $id | [22943, 22944] | index($id) )' /var/log/mongodb/mongod.log
この例に示されている jq
フィルターの詳細については、「jq ドキュメント」を参照してください。
日付範囲によるフィルタリング
タイムスタンプ フィールドでログ出力をフィルタリングして、返ってきたログエントリを特定の日付範囲に制限することで、ログ出力をさらに絞り込むことができます。たとえば、次の例では、2020 年 4 月 15 日に発生したすべてのログ エントリが返されます。
jq 'select(.t["$date"] >= "2020-04-15T00:00:00.000" and .t["$date"] <= "2020-04-15T23:59:59.999")' /var/log/mongodb/mongod.log
この構文には、タイムゾーンオフセットを除いた、ミリ秒単位の完全なタイムスタンプが含まれることに注意してください。
日付範囲によるフィルタリングを上記の例と組み合わせることで、週次レポートや年ごとのサマリーなどを作成できます。次の構文は、前出の「接続モニタリング」の例を拡大して、結果を 2020 年 5 月の結果に限定したものです。
jq 'select(.t["$date"] >= "2020-05-01T00:00:00.000" and .t["$date"] <= "2020-05-31T23:59:59.999" and .attr.remote)' /var/log/mongodb/mongod.log
この例に示されている jq
フィルターの詳細については、「jq ドキュメント」を参照してください。
ログ取り込みサービス
ログ取り込みサービスは、ログファイルを通常は分散システムのクラスターから取り込んで集約し、そのデータを中央ロケーションで継続的に分析するサードパーティ製プロダクトです。
JSON ログ形式を使用すると、ログの取り込みサービスおよび分析サービスを使用する際の柔軟性が向上します。一般的に、プレーンテキストのログは、これらの製品で使用する前に何らかの変換を必要とするのに対し、JSON ファイルは、サービスにによってはそのまま使用できます。さらに、JSON 形式のログでは、キー値構造により、関心のあるフィールドを特定してインポートし、残りを省略できるため、これらのサービスでフィルタリングを実行する際、より詳細な制御が可能です。
詳しくは、お客様のサードパーティ製ログ取り込みサービスで提供されているドキュメントを参照してください。
ログメッセージの例
以下は、JSON 形式で出力されたログ メッセージの例です。
これらのログ メッセージは、便宜上、 pretty-printed 形式で表示されます。
起動時の警告
以下は、起動時の警告の例です。
{ "t": { "$date": "2020-05-20T19:17:06.188+00:00" }, "s": "W", "c": "CONTROL", "id": 22120, "ctx": "initandlisten", "svc": "R", "msg": "Access control is not enabled for the database. Read and write access to data and configuration is unrestricted", "tags": [ "startupWarnings" ] }
クライアント接続
以下は、クライアント データを含むクライアント接続の例です。
{ "t": { "$date": "2020-05-20T19:18:40.604+00:00" }, "s": "I", "c": "NETWORK", "id": 51800, "ctx": "conn281", "svc": "R", "msg": "client metadata", "attr": { "remote": "192.168.14.15:37666", "client": "conn281", "doc": { "application": { "name": "MongoDB Shell" }, "driver": { "name": "MongoDB Internal Client", "version": "4.4.0" }, "os": { "type": "Linux", "name": "CentOS Linux release 8.0.1905 (Core) ", "architecture": "x86_64", "version": "Kernel 4.18.0-80.11.2.el8_0.x86_64" } } } }
低速操作
MongoDB 8 . 0 以降では、低速操作は、操作の合計レイテンシではなく、MongoDB でその操作にかかった時間に基づいてログに記録されます。
低速オペレーション ログのメトリクスを使用して、ライフサイクルのどの操作に時間がかかったかを特定できます。これにより、パフォーマンスの向上が可能か識別できます。
次のログ メッセージの例では、次のようになります。
クエリの実行中にリソースが待機していた時間は、次のメトリクスに表示されます。
queues.execution.totalTimeQueuedMicros
timeAcquiringMicros
workingMillis
は、MongoDB で操作にかかった時間です。durationMillis
は、操作の合計レイテンシです。
{ "t":{ "$date":"2024-06-01T13:24:10.034+00:00" }, "s":"I", "c":"COMMAND", "id":51803, "ctx":"conn3", "msg":"Slow query", "attr":{ "type":"command", "isFromUserConnection":true, "ns":"db.coll", "collectionType":"normal", "appName":"MongoDB Shell", "command":{ "find":"coll", "filter":{ "b":-1 }, "sort":{ "splitPoint":1 }, "readConcern":{ }, "$db":"db" }, "planSummary":"COLLSCAN", "planningTimeMicros":87, "keysExamined":0, "docsExamined":20889, "hasSortStage":true, "nBatches":1, "cursorExhausted":true, "numYields":164, "nreturned":99, "planCacheShapeHash":"9C05019A", "planCacheKey":"C41063D6", "queryFramework":"classic", "reslen":96, "locks":{ "ReplicationStateTransition":{ "acquireCount":{ "w":3 } }, "Global":{ "acquireCount":{ "r":327, "w":1 } }, "Database":{ "acquireCount":{ "r":1 }, "acquireWaitCount":{ "r":1 }, "timeAcquiringMicros":{ "r":2814 } }, "Collection":{ "acquireCount":{ "w":1 } } }, "flowControl":{ "acquireCount":1, "acquireWaitCount":1, "timeAcquiringMicros":8387 }, "readConcern":{ "level":"local", "provenance":"implicitDefault" }, "storage":{ }, "cpuNanos":20987385, "remote":"127.0.0.1:47150", "protocol":"op_msg", "queues":{ "ingress":{ "admissions":7, "totalTimeQueuedMicros":0 }, "execution":{ "admissions":328, "totalTimeQueuedMicros":2109 } }, "workingMillis":89, "durationMillis":101 } }
MongoDB 8.0以降、既存のqueryHash
フィールドの名前がplanCacheShapeHash
に変更されます。 以前のバージョンの MongoDB を使用している場合は、 planCacheShapeHash
ではなくqueryHash
が表示されます。
エスケープ
以下は、属性オブジェクトの setName
フィールドに表示されている、文字のエスケープの例です。
{ "t": { "$date": "2020-05-20T19:11:09.268+00:00" }, "s": "I", "c": "REPL", "id": 21752, "ctx": "ReplCoord-0", "svc": "R", "msg": "Scheduling remote command request", "attr": { "context": "vote request", "request": "RemoteCommand 229 -- target:localhost:27003 db:admin cmd:{ replSetRequestVotes: 1, setName: \"my-replica-name\", dryRun: true, term: 3, candidateIndex: 0, configVersion: 2, configTerm: 3, lastAppliedOpTime: { ts: Timestamp(1589915409, 1), t: 3 } }" } }
ビュー
MongoDB5 .0 以降、ビューに対する低速クエリのログ メッセージには、ビューの詳細を含む resolvedViews
フィールドが含まれます。
"resolvedViews": [ { "viewNamespace": <String>, // namespace and view name "dependencyChain": <Array of strings>, // view name and collection "resolvedPipeline": <Array of documents> // aggregation pipeline for view } ]
以下の例では、test
データベースを使用して、myCollection
内のドキュメントを firstName
フィールドでソートする myView
という名前のビューを作成します。
use test db.createView( "myView", "myCollection", [ { $sort: { "firstName" : 1 } } ] )
低速クエリが myView
で実行されるものとします。次のログ メッセージの例には、myView
の resolvedViews
フィールドが含まれています。
{ "t": { "$date": "2021-09-30T17:53:54.646+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn249", "svc": "R", "msg": "Slow query", "attr": { "type": "command", "ns": "test.myView", "appName": "MongoDB Shell", "command": { "find": "myView", "filter": {}, "lsid": { "id": { "$uuid": "ad176471-60e5-4e82-b977-156a9970d30f" } }, "$db": "test" }, "planSummary":"COLLSCAN", "resolvedViews": [ { "viewNamespace": "test.myView", "dependencyChain": [ "myView", "myCollection" ], "resolvedPipeline": [ { "$sort": { "firstName": 1 } } ] } ], "keysExamined": 0, "docsExamined": 1, "hasSortStage": true, "cursorExhausted": true, "numYields": 0, "nreturned": 1, "planCacheShapeHash": "3344645B", "planCacheKey": "1D3DE690", "queryFramework": "classic" "reslen": 134, "locks": { "ParallelBatchWriterMode": { "acquireCount": { "r": 1 } }, "ReplicationStateTransition": { "acquireCount": { "w": 1 } }, "Global": { "acquireCount": { "r": 4 } }, "Database": { "acquireCount": {"r": 1 } }, "Collection": { "acquireCount": { "r": 1 } }, "Mutex": { "acquireCount": { "r": 4 } } }, "storage": {}, "remote": "127.0.0.1:34868", "protocol": "op_msg", "workingMillis": 0, "durationMillis": 0 } } }
MongoDB 8.0以降、既存のqueryHash
フィールドの名前がplanCacheShapeHash
に変更されます。 以前のバージョンの MongoDB を使用している場合は、 planCacheShapeHash
ではなくqueryHash
が表示されます。
承認
MongoDB 5 . 0以降では、低速クエリのログ メッセージにsystem.profile.authorization
セクションが含まれます。これらのメトリクスは、ユーザー承認キャッシュの競合が原因でリクエストが遅延しているかを判断するのに役立ちます。
"authorization": { "startedUserCacheAcquisitionAttempts": 1, "completedUserCacheAcquisitionAttempts": 1, "userCacheWaitTimeMicros": 508 },
セッション ワークフロー ログ メッセージ
MongoDB 6.3 以降では、操作応答の送信時間がslowms のしきい値オプションを超えると、ログにメッセージが追加されます。
このメッセージはセッション ワークフロー ログ メッセージと呼ばれ、データベースセッションで操作を実行するためのさまざまな時間が含まれます。
セッション ワークフロー ログ メッセージの例
{ "t": { "$date": "2022-12-14T17:22:44.233+00:00" }, "s": "I", "c": "EXECUTOR", "id": 6983000, "ctx": "conn1", "svc": "R", "msg": "Slow network response send time", "attr": { "elapsed": { "totalMillis": 109, "activeMillis": 30, "receiveWorkMillis": 2, "processWorkMillis": 10, "sendResponseMillis": 22, "yieldMillis": 15, "finalizeMillis": 30 } } }
時間はミリ秒単位です。
sendResponseMillis
が slowms しきい値オプションを超えると、セッション ワークフロー メッセージがログに追加されます。
フィールド | 説明 |
---|---|
| セッション内で操作を実行するのにかかる合計時間。これには、メッセージを受信するまでの待機時間も含まれます。 |
| メッセージを受信してから、そのメッセージに関連した操作が完了するまでの時間。応答の送信とクリーンアップの実行にかかる時間も含みます。 |
| ネットワーク経由で操作情報を受信するまでの時間。 |
| 操作を処理し、応答を作成する時間。 |
| 応答を送信する時間。 |
| ワーカー スレッドが解放されてから、再び使用されるまでの時間。 |
| セッション ワークフローを終了して閉じるまでの時間。 |
接続取得からワイヤ ログ メッセージ
MongoDB 6.3 以降では、サーバー接続の取得からネットワーク経由でサーバーに送信するバイトの書き込みまでの操作待機時間が 1 ミリ秒を超えると、ログにメッセージが追加されます。
デフォルトでは、メッセージは "I"
情報レベルでログに記録され、ログ メッセージが多くなりすぎるのを避けるために最大で 1 秒に 1 回ログに記録されます。ログ メッセージをすべて取得する必要がある場合は、ログ レベルをデバッグに変更してください。
操作待機時間が 1 ミリ秒を超え、直近 1 秒以内にメッセージが情報レベルでログに記録された場合、次のメッセージはデバッグ レベルでログに記録されます。それ以外の場合、次のメッセージは情報レベルでログに記録されます。
ログメッセージの例
{ "t": { "$date":"2023-01-31T15:22:29.473+00:00" }, "s": "I", "c": "NETWORK", "id": 6496702, "ctx": "ReplicaSetMonitor-TaskExecutor", "svc": "R", "msg": "Acquired connection for remote operation and completed writing to wire", "attr": { "durationMicros": 1683 } }
以下の表では、attr
内の durationMicros
フィールドを説明しています。
フィールド | 説明 |
---|---|
| サーバー接続の取得から、ネットワーク経由でサーバーに送信するバイトの書き込みまでの操作待機時間(マイクロ秒単位)。 |
キャッシュの更新時間
MongoDB 6 . 1 以降では、低速クエリのログ メッセージには、以下のキャッシュ更新時間フィールドが含まれます。
catalogCacheDatabaseLookupDurationMillis
catalogCacheCollectionLookupDurationMillis
databaseVersionRefreshDurationMillis
shardVersionRefreshMillis
MongoDB 7 . 0 以降では、低速クエリのログ メッセージには、操作がインデックス キャッシュから情報を取得するためにかかった時間を示す catalogCacheIndexLookupDurationMillis
フィールドも含まれます。このリリースではまた、shardVersionRefreshMillis
フィールドの名前が placementVersionRefreshMillis
に変更されます。
以下の例には、次のアイテムが含まれます。
catalogCacheDatabaseLookupDurationMillis
catalogCacheCollectionLookupDurationMillis
catalogCacheIndexLookupDurationMillis
{ "t": { "$date": "2023-03-17T09:47:55.929+00:00" }, "s": "I", "c": "COMMAND", "id": 51803, "ctx": "conn14", "svc": "R", "msg": "Slow query", "attr": { "type": "command", "ns": "db.coll", "appName": "MongoDB Shell", "command": { "insert": "coll", "ordered": true, "lsid": { "id": { "$uuid": "5d50b19c-8559-420a-a122-8834e012274a" } }, "$clusterTime": { "clusterTime": { "$timestamp": { "t": 1679046398, "i": 8 } }, "signature": { "hash": { "$binary": { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "0" } }, "keyId": 0 } }, "$db": "db" }, "catalogCacheDatabaseLookupDurationMillis": 19, "catalogCacheCollectionLookupDurationMillis": 68, "catalogCacheIndexLookupDurationMillis": 16026, "nShards": 1, "ninserted": 1, "numYields": 232, "reslen": 96, "readConcern": { "level": "local", "provenance": "implicitDefault", }, "cpuNanos": 29640339, "remote": "127.0.0.1:48510", "protocol": "op_msg", "remoteOpWaitMillis": 4078, "workingMillis": 20334, "durationMillis": 20334 } }
Linux Syslog の制限事項
Linux システムでは、メッセージは Linux 構成ファイル /etc/systemd/journald.conf
で定義されたルールに従います。デフォルトでは、ログ メッセージのバーストの上限は 30 秒間に 1,000 メッセージです。表示されるメッセージ数を増やすには、/etc/systemd/journald.conf
の RateLimitBurst
パラメータを増やします。
ログのダウンロード
MongoDB Atlas を使用して、データベース配置で選択したホスト名またはプロセスのログを含む zip ファイルをダウンロードできます。詳しくは、「MongoDB ログの表示とダウンロード」を参照してください。