[SERVER-21707] slowms should include time spent waiting for writeConcern fulfillment Created: 01/Dec/15  Updated: 01/Dec/15  Resolved: 01/Dec/15

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: None
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: James Wahlin Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-18067 Add the time spent waiting for write ... Closed
Related
Participants:

 Description   

mongoD slowms logging includes time spent waiting for writeConcern fulfillment. It does not currently split out the time spent executing the write locally vs. time spent waiting for replication when w >= 2. We should provide the write concern wait time separately to allow for easier diagnosis when slow.

The following is an example of an insert that spent 1000ms waiting for write concern acknowledgement (before timing out).

2015-12-01T09:22:10.529-0500 d20011| 2015-12-01T09:22:10.529-0500 I COMMAND  [conn1] command test.foo command: insert { insert: "foo", documents: [ { a: 1.0 } ], writeConcern: { w: 3.0, wtimeout: 1000.0 } } ntoreturn:1 ntoskip:0 ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:190 locks:{ Global: { acquireCount: { r: 4, w: 4 } }, Database: { acquireCount: { w: 3, W: 1 } }, Collection: { acquireCount: { W: 1 } }, Metadata: { acquireCount: { w: 2 } }, oplog: { acquireCount: { w: 2 } } } protocol:op_command 1041ms



 Comments   
Comment by Scott Hernandez (Inactive) [ 01/Dec/15 ]

dup of SERVER-18067

Generated at Thu Feb 08 03:58:11 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.