[SERVER-57639] Decrease the amount of logs emitted when closing a connection in v5.0 Created: 11/Jun/21  Updated: 29/Oct/23  Resolved: 25/Jun/21

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 5.0.0-rc1
Fix Version/s: 5.0.0-rc5, 5.1.0-rc0

Type: Improvement Priority: Major - P3
Reporter: Blake Oler Assignee: Amirsaman Memaripour
Resolution: Fixed Votes: 2
Labels: 5.0-dogfooding, post-rc0, servicearch-wfbf-day
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Problem/Incident
Related
related to SERVER-58105 Improve exception handling in ASIOSes... Backlog
Backwards Compatibility: Fully Compatible
Backport Requested:
v5.0
Sprint: Service Arch 2021-06-28
Participants:
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



 Comments   
Comment by Vivian Ge (Inactive) [ 06/Oct/21 ]

Updating the fixversion since branching activities occurred yesterday. This ticket will be in rc0 when it’s been triggered. For more active release information, please keep an eye on #server-release. Thank you!

Comment by Githook User [ 28/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Consolidate scheduling of ServiceStateMachine loops

(cherry picked from commit ac2c0acc3934ae97b35c6ca5d9f72a360713bfe2)
Branch: v5.0
https://github.com/mongodb/mongo/commit/b6a243b478a6448f4b3f73cf064fd146a4a69d33

Comment by Githook User [ 28/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Remove unused code from ServiceStateMachine

(cherry picked from commit 791a1f7ce673eb16b26c8bc95cc058f83c234dbc)
Branch: v5.0
https://github.com/mongodb/mongo/commit/f767d1319fdc07f7e01af01e4057bcea09088844

Comment by Githook User [ 28/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Log termination of sessions at debug level

(cherry picked from commit d48cea2e51ea038956f0476fcc9f6653025cd26e)
Branch: v5.0
https://github.com/mongodb/mongo/commit/b3fe874d0d7523549229fa09d0b5c76525acbcf9

Comment by Githook User [ 25/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Consolidate scheduling of ServiceStateMachine loops
Branch: master
https://github.com/mongodb/mongo/commit/ac2c0acc3934ae97b35c6ca5d9f72a360713bfe2

Comment by Githook User [ 25/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Remove unused code from ServiceStateMachine
Branch: master
https://github.com/mongodb/mongo/commit/791a1f7ce673eb16b26c8bc95cc058f83c234dbc

Comment by Githook User [ 25/Jun/21 ]

Author:

{'name': 'Amirsaman Memaripour', 'email': 'amirsaman.memaripour@mongodb.com', 'username': 'samanca'}

Message: SERVER-57639 Log termination of sessions at debug level
Branch: master
https://github.com/mongodb/mongo/commit/d48cea2e51ea038956f0476fcc9f6653025cd26e

Generated at Thu Feb 08 05:42:24 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.