-
Type:
Bug
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: Diagnostics, Replication
-
Fully Compatible
-
ALL
-
v4.0
-
Repl 2018-08-13
We should add an identifier to the log message for slow transactions so that we know the information logged corresponds to a transaction. This could be as simple as prefixing the log message with 'transaction'. Currently, slow transaction log messages look like the following:
I COMMAND [main] parameters:{ lsid: { id: UUID("1d7db5e4-e684-482e-b903-eb23203d14d8"), uid: BinData(0, E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855) }, txnNumber: 1, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(0, 0), keysExamined:1 docsExamined:1 nMatched:1 nModified:1 ninserted:1 ndeleted:1 nmoved:1 keysInserted:1 keysDeleted:1 prepareReadConflicts:1 writeConflicts:1 terminationCause:committed timeActiveMicros:11142 timeInactiveMicros:3 numYields:0 locks:{ Global: { acquireCount: { r: 6, w: 4 } }, Database: { acquireCount: { r: 1, w: 1, W: 2 } }, Collection: { acquireCount: { R: 1 } }, oplog: { acquireCount: { W: 1 } } } 11ms
We could change them to look to something like:
I COMMAND [main] transaction parameters:{ lsid: { id: UUID("1d7db5e4-e684-482e-b903-eb23203d14d8"), uid: BinData(0, E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855) }, txnNumber: 1, autocommit: false, readConcern: { level: "snapshot" } }, readTimestamp:Timestamp(0, 0), keysExamined:1 docsExamined:1 nMatched:1 nModified:1 ninserted:1 ndeleted:1 nmoved:1 keysInserted:1 keysDeleted:1 prepareReadConflicts:1 writeConflicts:1 terminationCause:committed timeActiveMicros:11142 timeInactiveMicros:3 numYields:0 locks:{ Global: { acquireCount: { r: 6, w: 4 } }, Database: { acquireCount: { r: 1, w: 1, W: 2 } }, Collection: { acquireCount: { R: 1 } }, oplog: { acquireCount: { W: 1 } } } 11ms
- is related to
-
SERVER-35433 Log slow transactions when they finish
-
- Closed
-