[SERVER-81157] Primary server change detected duration logging can be misleading Created: 18/Sep/23  Updated: 22/Jan/24

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

Type: Bug Priority: Major - P3
Reporter: Adam Harrison Assignee: Rachita Dhawan
Resolution: Unresolved Votes: 0
Labels: cs-subteam1, sharding-nyc-subteam1
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
Assigned Teams:
Sharding NYC
Operating System: ALL
Participants:

 Description   

The durationMillis value recorded when logging changes in the Primary state of a replica set is recording the time between subsequent instances of these messages. For example:

{"t":{"$date":"2023-09-18T10:39:47.885-07:00"},"s":"I",  "c":"NETWORK",  "id":6006301, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Replica set primary server change detected","attr":{"replicaSet":"replset","topologyType":"ReplicaSetNoPrimary","primary":"Unknown","durationMillis":3846}}
 
{"t":{"$date":"2023-09-18T10:39:57.891-07:00"},"s":"I",  "c":"NETWORK",  "id":6006301, "ctx":"ReplicaSetMonitor-TaskExecutor","msg":"Replica set primary server change detected","attr":{"replicaSet":"replset","topologyType":"ReplicaSetWithPrimary","primary":"localhost:27017","durationMillis":10005}} 

These duration values are misleading.

We should either remove the durationMillis value from these messages, or have the value logged for duration better reflect the time required to determine that a change was detected.


Generated at Thu Feb 08 06:45:39 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.