|
We currently track and log statistics for slow transactions
mongodb.log.2019-02-21T16-06-35:2019-02-21T12:54:34.271+0000 W NETWORK [conn29896] no SSL certificate provided by peer
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T12:54:34.273+0000 I NETWORK [conn29896] received client metadata from xxx.xxx.x.x:58319 conn29896: { driver: { name: "mongo-java-driver", version: "3.8.2" }, os: { type: "Windows", name: "Windows 10", architecture: "amd64", version: "10.0" }, platform: "Java/Oracle Corporation/1.8.0_74-b02" }
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T12:54:35.946+0000 I ACCESS [conn29896] Successfully authenticated as principal coreapi-dev on admin
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T12:55:21.453+0000 I TXN [conn29896] transaction parameters:{ lsid: { id: UUID("a91391af-e6b8-4956-8cd7-8bdfda3f7f37"), uid: BinData(0, 335C52DA77A8915F0E136B9BAADC6B97D45222CB52E41FAAE098BDA85E98DE30) }, txnNumber: 4, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1550753706, 1), keysExamined:8 docsExamined:8 ninserted:3 keysInserted:19 terminationCause:committed timeActiveMicros:14066 timeInactiveMicros:9719327 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 5 } } } 9733ms
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T12:55:53.494+0000 I TXN [conn29896] transaction parameters:{ lsid: { id: UUID("a91391af-e6b8-4956-8cd7-8bdfda3f7f37"), uid: BinData(0, 335C52DA77A8915F0E136B9BAADC6B97D45222CB52E41FAAE098BDA85E98DE30) }, txnNumber: 5, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1550753746, 1), keysExamined:7 docsExamined:7 ninserted:3 keysInserted:17 terminationCause:committed timeActiveMicros:7906 timeInactiveMicros:5400186 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 5 } } } 5408ms
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T13:11:37.795+0000 I TXN [conn29896] transaction parameters:{ lsid: { id: UUID("448dc2f9-ed81-4ea6-acc6-761f7591d3c7"), uid: BinData(0, 335C52DA77A8915F0E136B9BAADC6B97D45222CB52E41FAAE098BDA85E98DE30) }, txnNumber: 64, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(1550754686, 1), keysExamined:18 docsExamined:15 ninserted:7 keysInserted:50 terminationCause:committed timeActiveMicros:10910 timeInactiveMicros:6050666 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 5 } } } 6061ms
|
mongodb.log.2019-02-21T16-06-35:2019-02-21T13:26:06.377+0000 I NETWORK [conn29896] end connection xxx.xxx.x.x:58319 (89 connections now open)
|
However, this doesn't help us determine what queries might have been slow within these transactions. It would be helpful to interleave the individual statements (as we do with all other slow operations) that are executed in the transaction in the logs.
|