[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:07.630+0000 I REPL     [replexec-12] transition to PRIMARY from SECONDARY
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:08.793+0000 I REPL     [rsSync-0] transition to primary complete; database writes are now permitted
...
[ShardedClusterFixture:job0:configsvr:node2] 2019-04-03T05:58:08.822+0000 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
[ShardedClusterFixture:job0:configsvr:node2] 2019-04-03T05:58:08.864+0000 I CONTROL  [signalProcessingThread] shutting down with code:0
[ShardedClusterFixture:job0:configsvr:node2] Successfully stopped the mongod on port 20002.
...
[ShardedClusterFixture:job0:configsvr:node1] 2019-04-03T05:58:08.873+0000 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
[ShardedClusterFixture:job0:configsvr:node1] 2019-04-03T05:58:10.009+0000 I CONTROL  [signalProcessingThread] shutting down with code:0
[ShardedClusterFixture:job0:configsvr:node1] Successfully stopped the mongod on port 20001.
...
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I CONTROL  [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn58] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn58] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20008:1554270806:-6701597684633815355" }, update: { $set: { ping: new Date(1554271087853) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271088, 1), signature: { hash: BinData(0, 41AC32E76A9C92E5A8B056F53B1AE810014BAA17), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:732 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1159ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn42] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn42] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20004:1554270806:765596494582915214" }, update: { $set: { ping: new Date(1554271087839) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271088, 1), signature: { hash: BinData(0, 41AC32E76A9C92E5A8B056F53B1AE810014BAA17), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:730 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1174ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn390] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn390] command config.$cmd command: update { update: "mongos", bypassDocumentValidation: false, ordered: true, updates: [ { q: { _id: "ip-10-122-29-79:20009" }, u: { $set: { _id: "ip-10-122-29-79:20009", ping: new Date(1554271088643), up: 282, waiting: true, mongoVersion: "4.0.8-18-g57edce7396", advisoryHostFQDNs: [ "ip-10-122-29-79.ec2.internal" ] } }, multi: false, upsert: true } ], writeConcern: { w: "majority", wtimeout: 60000 }, allowImplicitCollectionCreation: true, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271088, 3), signature: { hash: BinData(0, 41AC32E76A9C92E5A8B056F53B1AE810014BAA17), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271088, 3), t: 28 } }, $db: "config" } numYields:0 reslen:678 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 871ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn45] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn45] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20005:1554270806:-4758601724122253121" }, update: { $set: { ping: new Date(1554271087835) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271087, 1), signature: { hash: BinData(0, B31C77A13DF90FED05319D6D16D0EB70B6E17179), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:732 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1177ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn59] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn59] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20007:1554270806:2082168933714807912" }, update: { $set: { ping: new Date(1554271087831) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271087, 1), signature: { hash: BinData(0, B31C77A13DF90FED05319D6D16D0EB70B6E17179), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:731 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1181ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.017+0000 I COMMAND  [conn60] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.018+0000 I COMMAND  [conn60] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20006:1554270806:-7144896684610494338" }, update: { $set: { ping: new Date(1554271087844) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271087, 1), signature: { hash: BinData(0, B31C77A13DF90FED05319D6D16D0EB70B6E17179), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:732 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1169ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.018+0000 I COMMAND  [conn46] Timed out obtaining lock while trying to gather storage statistics for a slow operation
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.018+0000 I COMMAND  [conn46] command config.lockpings command: findAndModify { findAndModify: "lockpings", query: { _id: "ip-10-122-29-79:20003:1554270806:4471450513314286609" }, update: { $set: { ping: new Date(1554271087817) } }, upsert: true, writeConcern: { w: "majority", wtimeout: 15000 }, maxTimeMS: 30000, $replData: 1, $clusterTime: { clusterTime: Timestamp(1554271088, 1), signature: { hash: BinData(0, 41AC32E76A9C92E5A8B056F53B1AE810014BAA17), keyId: 6675542225062985757 } }, $configServerState: { opTime: { ts: Timestamp(1554271086, 12), t: 27 } }, $db: "config" } planSummary: IDHACK keysExamined:1 docsExamined:1 nMatched:1 nModified:1 keysInserted:1 keysDeleted:1 numYields:0 reslen:731 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 1196ms
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.927+0000 W SHARDING [replSetDistLockPinger] Failed to unlock lock with ts: 5ca44a887b55d5eac92903cd :: caused by :: NotMaster: Not primary while running findAndModify command on collection config.locks
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.928+0000 W SHARDING [replSetDistLockPinger] Failed to unlock lock with ts: 5ca44a887b55d5eac92903c8 :: caused by :: NotMaster: Not primary while running findAndModify command on collection config.locks
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.928+0000 W SHARDING [replSetDistLockPinger] Failed to unlock lock with ts: 5ca44a9d7b55d5eac92915e0 :: caused by :: NotMaster: Not primary while running findAndModify command on collection config.locks
[ShardedClusterFixture:job0:configsvr:node0] 2019-04-03T05:58:10.928+0000 W SHARDING [replSetDistLockPinger] Failed to unlock lock with ts: 5ca44a9d7b55d5eac92915da :: caused by :: NotMaster: Not primary while running findAndModify command on collection config.locks