Hi there,
after upgrading to MongoDB 5 we noticed a constant increase of User assertions in our monitoring.
Setting the log verbosity to 5, revealed that the assertions are about the following
error “HostUnreachable: Connection closed by peer”.
We found out that this error is caused by the command:
mongo --username user–password password–authenticationDatabase admin --quiet --eval ‘db.adminCommand(“ping”).ok’
which is our K8s readiness probe.
Also, for investigation, we set up a second deployment, this time with MongoDB 4 again. With debugging on, we were surprised to see that the HostUnreachable error can also be found in that deployment.
But there is a difference: there are no user assertions!!
So the error is present in both deployments (for whatever reason) but only MongoDB 5 issues the extra user assertion.
Is that a bug?
And - the obvious question: does anybody have an idea why our command can lead to the error in the first place? I cannot seem to find a way to work around it.
The logs for MongoDB 5 are as follows:
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"D3", "c":"-", "id":5127803, "ctx":"conn1938","msg":"Released the Client","attr":{"client":"conn1938"}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"D3", "c":"-", "id":5127803, "ctx":"conn1938","msg":"Released the Client","attr":{"client":"conn1938"}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"D4", "c":"NETWORK", "id":4898001, "ctx":"conn1938","msg":"Resetting ServiceExecutor context for client","attr":{"client":"conn1938","threadingModel":"dedicated","canUseReserved":false}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"D2", "c":"NETWORK", "id":5127900, "ctx":"conn1938","msg":"Ending session","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1938","msg":"Connection ended","attr":{"remote":"127.0.0.1:59924","uuid":"61a4b073-6636-443b-9246-c18070f1edcf","connectionId":1938,"connectionCount":24}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.985+00:00"},"s":"D2", "c":"NETWORK", "id":5763901, "ctx":"conn1938","msg":"Terminating session due to error","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
Oct 5, 2021 @ 11:17:33.985 {"t":{"$date":"2021-10-05T09:17:33.984+00:00"},"s":"D1", "c":"-", "id":23074, "ctx":"conn1938","msg":"User assertion","attr":{"error":"HostUnreachable: Connection closed by peer","file":"src/mongo/transport/service_state_machine.cpp","line":536}}
Oct 5, 2021 @ 11:17:33.984 {"t":{"$date":"2021-10-05T09:17:33.984+00:00"},"s":"D1", "c":"-", "id":23074, "ctx":"conn1938","msg":"User assertion","attr":{"error":"HostUnreachable: Connection closed by peer","file":"src/mongo/transport/service_state_machine.cpp","line":394}}
Oct 5, 2021 @ 11:17:33.984 {"t":{"$date":"2021-10-05T09:17:33.984+00:00"},"s":"D2", "c":"NETWORK", "id":22986, "ctx":"conn1938","msg":"Session from remote encountered a network error during SourceMessage","attr":{"remote":"127.0.0.1:59924","error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
Now the logs from MongoDB 4:
Oct 6, 2021 @ 10:50:31.231 {"t":{"$date":"2021-10-06T08:50:31.231+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn24021","msg":"Connection ended","attr":{"remote":"127.0.0.1:53324","connectionId":24021,"connectionCount":21}}
Oct 6, 2021 @ 10:50:31.231 {"t":{"$date":"2021-10-06T08:50:31.231+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn24021","msg":"Connection ended","attr":{"remote":"127.0.0.1:53324","connectionId":24021,"connectionCount":21}}
Oct 6, 2021 @ 10:50:31.231 {"t":{"$date":"2021-10-06T08:50:31.231+00:00"},"s":"D2", "c":"NETWORK", "id":22986, "ctx":"conn24021","msg":"Session from remote encountered a network error during SourceMessage","attr":{"remote":"127.0.0.1:53324","error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
Any insights anybody?
