Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-48214

ReplSetTest awaitReplication is too verbose

    XMLWordPrintable

    Details

      Description

      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
      

        Attachments

          Activity

            People

            Assignee:
            backlog-server-repl Backlog - Replication Team
            Reporter:
            milkie Eric Milkie
            Participants:
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated: