2021-08-11T01:22:03.479+0430 I  NETWORK  [conn88] received client metadata from 127.0.0.1:55914 conn88: { driver: { name: "PyMongo", version: "3.12.0" }, os: { type: "Linux", name: "Ubuntu 18.04 bionic", architecture: "x86_64", version: "4.4.0-19041-Microsoft" }, platform: "CPython 2.7.17.final.0" }
2021-08-11T01:22:03.482+0430 W  COMMAND  [conn84] Unable to gather storage statistics for a slow operation due to lock aquire timeout
2021-08-11T01:22:03.482+0430 W  COMMAND  [conn48] Unable to gather storage statistics for a slow operation due to lock aquire timeout
2021-08-11T01:22:03.482+0430 I  COMMAND  [conn84] command m312.$cmd command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a1') }, lsid: { id: UUID("15b2fa58-1c7c-43fc-aa98-c013d84aa6d0") }, $clusterTime: { clusterTime: Timestamp(1628628721, 5), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } numYields:0 ok:0 errMsg:"operation was interrupted" errName:ClientDisconnect errCode:279 reslen:242 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 1000625 } }, Mutex: { acquireCount: { r: 1 } } } protocol:op_msg 1092ms
2021-08-11T01:22:03.482+0430 I  COMMAND  [conn48] command m312.$cmd command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("2f79b199-8047-4d09-860e-5bc1a4a40076") }, $clusterTime: { clusterTime: Timestamp(1628628721, 5), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } numYields:0 ok:0 errMsg:"operation was interrupted" errName:ClientDisconnect errCode:279 reslen:242 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 1000558 } }, Mutex: { acquireCount: { r: 1 } } } protocol:op_msg 1079ms
2021-08-11T01:22:03.482+0430 I  NETWORK  [conn48] end connection 127.0.0.1:55874 (57 connections now open)
2021-08-11T01:22:03.482+0430 I  NETWORK  [conn84] end connection 127.0.0.1:55910 (56 connections now open)
2021-08-11T01:22:03.483+0430 I  INDEX    [conn44] index build: starting on m312.employees properties: { v: 2, key: { last_name: 1, first_name: 1 }, name: "last_name_1_first_name_1", ns: "m312.employees" } using method: Hybrid
2021-08-11T01:22:03.483+0430 I  INDEX    [conn44] build may temporarily use up to 200 megabytes of RAM
2021-08-11T01:22:03.484+0430 I  COMMAND  [conn52] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("c6e84546-cc45-4720-aa7f-9f4def352bde") }, $clusterTime: { clusterTime: Timestamp(1628628721, 6), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:597 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 964252 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 964ms
2021-08-11T01:22:03.484+0430 I  WRITE    [conn58] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 810724 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} 810ms
2021-08-11T01:22:03.484+0430 I  COMMAND  [conn58] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("08923107-1d5f-446a-81e0-86da57891d20") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 8), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 810724 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} protocol:op_msg 811ms
2021-08-11T01:22:03.484+0430 I  WRITE    [conn82] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 150499 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 7 } storage:{} 150ms
2021-08-11T01:22:03.484+0430 I  COMMAND  [conn82] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("4411b78a-1bb5-430a-aa65-35bbd825672e") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628722, 4), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 150499 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 7 } storage:{} protocol:op_msg 150ms
2021-08-11T01:22:03.484+0430 I  WRITE    [conn50] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 1005816 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} 1006ms
2021-08-11T01:22:03.485+0430 I  COMMAND  [conn50] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("7a201814-2a3f-41ce-a08d-2a45612d3b81") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 6), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 1005816 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} protocol:op_msg 1007ms
2021-08-11T01:22:03.485+0430 I  NETWORK  [conn50] end connection 127.0.0.1:55876 (55 connections now open)
2021-08-11T01:22:03.486+0430 I  COMMAND  [conn56] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("07f1149e-f796-4187-b018-e23a32396f2b") }, $clusterTime: { clusterTime: Timestamp(1628628721, 7), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 866117 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 868ms
2021-08-11T01:22:03.486+0430 I  COMMAND  [conn60] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("14259bf6-435e-4d94-8fc8-a7af7da0ac95") }, $clusterTime: { clusterTime: Timestamp(1628628721, 8), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 760886 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 763ms
2021-08-11T01:22:03.487+0430 I  COMMAND  [conn64] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("0d304cb1-e2c2-4a93-8aa1-d5673699904e") }, $clusterTime: { clusterTime: Timestamp(1628628721, 9), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 647748 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 650ms
2021-08-11T01:22:03.487+0430 I  WRITE    [conn66] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 588103 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} 591ms
2021-08-11T01:22:03.488+0430 I  COMMAND  [conn66] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("9d7250c7-62a5-4055-a920-5d0fa162f8a0") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 10), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 588103 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} protocol:op_msg 591ms
2021-08-11T01:22:03.488+0430 I  COMMAND  [conn68] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("71d988b9-57a4-4aa9-8100-c4d75370a815") }, $clusterTime: { clusterTime: Timestamp(1628628721, 10), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 537308 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 541ms
2021-08-11T01:22:03.489+0430 I  WRITE    [conn70] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 475410 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 5 } storage:{} 480ms
2021-08-11T01:22:03.489+0430 I  COMMAND  [conn70] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("0a4ff575-fbd7-488d-a6b3-7dc2aa322502") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628722, 1), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 475410 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 5 } storage:{} protocol:op_msg 480ms
2021-08-11T01:22:03.489+0430 I  COMMAND  [conn72] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("b6dbef75-b2df-4490-b66e-4ae0bc627bc3") }, $clusterTime: { clusterTime: Timestamp(1628628722, 1), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 427145 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 432ms
2021-08-11T01:22:03.490+0430 I  WRITE    [conn74] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 366969 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 20 } storage:{} 372ms
2021-08-11T01:22:03.490+0430 I  COMMAND  [conn74] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("c5386cf7-6b89-430a-9021-32979b4186be") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628722, 2), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 366969 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 20 } storage:{} protocol:op_msg 372ms
2021-08-11T01:22:03.490+0430 I  COMMAND  [conn76] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("b760a7c6-2ee0-40df-a43d-743edc466ef2") }, $clusterTime: { clusterTime: Timestamp(1628628722, 2), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 315742 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 321ms
2021-08-11T01:22:03.491+0430 I  WRITE    [conn78] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 250982 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} 257ms
2021-08-11T01:22:03.491+0430 I  COMMAND  [conn78] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("04002482-78a7-4574-a409-d11a4ecc3f5a") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628722, 3), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 250982 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 4 } storage:{} protocol:op_msg 257ms
2021-08-11T01:22:03.491+0430 I  COMMAND  [conn80] command m312.employees command: find { find: "employees", filter: { _id: ObjectId('6112e4e316b18b62f36195a2') }, lsid: { id: UUID("41277a4d-bebb-4fc0-ad2f-6cc12efa496d") }, $clusterTime: { clusterTime: Timestamp(1628628722, 3), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primaryPreferred" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:608 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 204913 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 211ms
2021-08-11T01:22:03.492+0430 I  WRITE    [conn62] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 690247 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 5 } storage:{} 698ms
2021-08-11T01:22:03.492+0430 I  COMMAND  [conn62] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("2328d165-3482-43a9-938a-6b1a90bded2a") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 9), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 2 } }, ReplicationStateTransition: { acquireCount: { w: 4 } }, Global: { acquireCount: { r: 1, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 690247 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 1, timeAcquiringMicros: 5 } storage:{} protocol:op_msg 698ms
2021-08-11T01:22:03.522+0430 I  WRITE    [conn46] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 writeConflicts:1 numYields:1 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 3 } }, ReplicationStateTransition: { acquireCount: { w: 3 } }, Global: { acquireCount: { w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 3 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 1126228 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 2, timeAcquiringMicros: 10 } storage:{} 1164ms
2021-08-11T01:22:03.522+0430 I  COMMAND  [conn46] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("b3166f3a-0417-44ef-bca6-f1dfe217e8bf") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 5), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:1 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 3 } }, ReplicationStateTransition: { acquireCount: { w: 5 } }, Global: { acquireCount: { r: 1, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 3 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 1126228 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 2, timeAcquiringMicros: 10 } storage:{} protocol:op_msg 1165ms
2021-08-11T01:22:03.522+0430 I  NETWORK  [conn46] end connection 127.0.0.1:55872 (54 connections now open)
2021-08-11T01:22:03.524+0430 I  WRITE    [conn54] update m312.employees command: { q: { _id: ObjectId('6112e4e316b18b62f36195a2') }, u: { $inc: { count: 1 } }, multi: false, upsert: false } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 writeConflicts:4 numYields:4 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 6 } }, ReplicationStateTransition: { acquireCount: { w: 6 } }, Global: { acquireCount: { w: 6 } }, Database: { acquireCount: { w: 6 } }, Collection: { acquireCount: { w: 6 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 917561 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 5, timeAcquiringMicros: 24 } storage:{} 958ms
2021-08-11T01:22:03.524+0430 I  COMMAND  [conn54] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("7fc61e85-28dc-4a74-a3ed-385ef497af8e") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 7), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:4 reslen:245 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 6 } }, ReplicationStateTransition: { acquireCount: { w: 8 } }, Global: { acquireCount: { r: 1, w: 6 } }, Database: { acquireCount: { w: 6 } }, Collection: { acquireCount: { w: 6 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 917561 } }, Mutex: { acquireCount: { r: 3 } } } flowControl:{ acquireCount: 5, timeAcquiringMicros: 24 } storage:{} protocol:op_msg 958ms
2021-08-11T01:22:03.531+0430 I  COMMAND  [conn85] command m312.$cmd command: update { update: "employees", ordered: true, lsid: { id: UUID("b3166f3a-0417-44ef-bca6-f1dfe217e8bf") }, txnNumber: 10, $clusterTime: { clusterTime: Timestamp(1628628721, 5), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:0 reslen:245 locks:{ ReplicationStateTransition: { acquireCount: { w: 2 } }, Global: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 162ms
2021-08-11T01:22:06.000+0430 I  -        [conn44]   Index Build: scanning collection: 982300/1010893 97%
2021-08-11T01:22:06.091+0430 I  INDEX    [conn44] index build: collection scan done. scanned 1010893 total records in 2 seconds
2021-08-11T01:22:08.701+0430 I  INDEX    [conn44] index build: inserted 1010893 keys from external sorter into index in 2 seconds
2021-08-11T01:22:08.736+0430 I  INDEX    [conn44] index build: done building index last_name_1_first_name_1 on ns m312.employees
2021-08-11T01:22:08.860+0430 I  COMMAND  [conn44] command m312.employees command: createIndexes { createIndexes: "employees", indexes: [ { name: "last_name_1_first_name_1", key: { last_name: 1, first_name: 1 } } ], lsid: { id: UUID("0e31787c-7c37-4ff9-afba-389cbfc58c45") }, $clusterTime: { clusterTime: Timestamp(1628628713, 4), signature: { keyId: 0, hash: BinData(0, 0000000000000000000000000000000000000000) } }, $db: "m312", $readPreference: { mode: "primary" } } numYields:7897 reslen:239 locks:{ ParallelBatchWriterMode: { acquireCount: { r: 7899 } }, ReplicationStateTransition: { acquireCount: { w: 7900 } }, Global: { acquireCount: { r: 1, w: 7899 } }, Database: { acquireCount: { r: 1, w: 7899 } }, Collection: { acquireCount: { r: 7899, w: 1, R: 1, W: 2 } }, Mutex: { acquireCount: { r: 4 } } } flowControl:{ acquireCount: 7898, timeAcquiringMicros: 32771 } storage:{ data: { bytesRead: 961568661, timeReadingMicros: 1175001 }, timeWaitingMicros: { cache: 6 } } protocol:op_msg 6507ms
2021-08-11T01:22:18.862+0430 I  NETWORK  [conn45] end connection 127.0.0.1:55871 (53 connections now open)
2021-08-11T01:22:18.872+0430 I  NETWORK  [conn49] end connection 127.0.0.1:55875 (52 connections now open)
2021-08-11T01:22:18.880+0430 I  NETWORK  [conn67] end connection 127.0.0.1:55893 (51 connections now open)
2021-08-11T01:22:18.880+0430 I  NETWORK  [conn66] end connection 127.0.0.1:55892 (50 connections now open)