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

Decrease the amount of logs emitted when closing a connection in v5.0

    XMLWordPrintable

    Details

    • Backwards Compatibility:
      Fully Compatible
    • Backport Requested:
      v5.0
    • Sprint:
      Service Arch 2021-06-28
    • Linked BF Score:
      135

      Description

      Running any given set of repl/sharding jsTests on 4.4 and 5.0 has a difference in the amount of information-level logs emitted when a connection is closed.

      4.4:

      [js_test:hash_crud] d20021| 2021-06-10T15:36:57.357+00:00 I  NETWORK  22944   [conn30] "Connection ended","attr":{"remote":"10.122.10.199:59354","uuid":"ca7a0c27-d846-4fc1-942b-b33289bd2498","connectionId":30,"connectionCount":12}

      5.0:

      [js_test:hash_crud] d20021| 2021-06-10T15:36:57.357+00:00 W  EXECUTOR 4910400 [conn30] "Terminating session due to error","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}
      [js_test:hash_crud] d20021| 2021-06-10T15:36:57.357+00:00 I  NETWORK  5127900 [conn30] "Ending session","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}
      [js_test:hash_crud] d20021| 2021-06-10T15:36:57.357+00:00 I  NETWORK  22944   [conn30] "Connection ended","attr":{"remote":"10.122.10.199:59354","uuid":"ca7a0c27-d846-4fc1-942b-b33289bd2498","connectionId":30,"connectionCount":12} 

      This behavior can quickly swamp the log – in a given jsTest, I see an average of 200 connection ended logs (mostly due to the hello command*). On top of this, the server triage team has concerns that the "terminating session due to error" message will scare users who are trying to upgrade from 4.4 to 5.0 (HELP-25086).

      This ticket is aimed to suppress these extra logs if possible, and change them to debug level.

      *This was verified by adding printStackTrace to the lowest-level of these messages, and the vast majority of these messages were coming from a connection being closed while the recipient side of a hello command was waiting in ReplicationCoordinator::awaitHelloResponse

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              amirsaman.memaripour Amirsaman Memaripour
              Reporter:
              blake.oler Blake Oler
              Participants:
              Votes:
              2 Vote for this issue
              Watchers:
              6 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: