-
Type:
Improvement
-
Resolution: Unresolved
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: Replication
-
Labels:
-
Replication
While awaitReplication is looping, it logs messages every 2 tenths of a second. In some cases, it can log 9 or more lines in each batch of messages. For some tests, especially when they are failing, this can overwhelm the log and cause lengthy load times and web browser memory issues, making the BF diagnosis experience worse than it needs to be. I think some of these messages can be eliminated or combined while still giving all the information.
Example:
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.896+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: checking secondaries against latest primary optime { "ts" : Timestamp(1589441508, 23192), "t" : NumberLong(1) }
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.897+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: checking secondary #0: ip-10-122-50-53:20271
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.898+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: optime for secondary #0, ip-10-122-50-53:20271, is { "ts" : Timestamp(1589441505, 17394), "t" : NumberLong(1) } but latest is { "ts" : Timestamp(1589441508, 23192), "t" : NumberLong(1) }
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.899+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: secondary #0, ip-10-122-50-53:20271, is NOT synced
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.899+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: secondary #0, ip-10-122-50-53:20271, has made progress. Resetting awaitReplication timeout
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.899+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: checking secondaries against latest primary optime { "ts" : Timestamp(1589441508, 23192), "t" : NumberLong(1) }
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.900+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: checking secondary #0: ip-10-122-50-53:20271
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.901+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: optime for secondary #0, ip-10-122-50-53:20271, is { "ts" : Timestamp(1589441505, 17394), "t" : NumberLong(1) } but latest is { "ts" : Timestamp(1589441508, 23192), "t" : NumberLong(1) }
[js_test:backup_restore_stop_start] 2020-05-14T07:31:48.901+0000 sh9428| [WaitForReplication:job0] ReplSetTest awaitReplication: secondary #0, ip-10-122-50-53:20271, is NOT synced