...
When a client connects to the server and subsequently disconnects, the mongod log includes line items showing the connection being established and closed: {"t":{"$date":"2020-04-13T20:42:42.167-04:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59","msg":"client metadata","attr":{"remote":"127.0.0.1:54986","client":"conn59","doc":{"driver":{"name":"mongo-ruby-driver","version":"2.11. 4"},"os":{"type":"linux","name":"linux-gnu","architecture":"x86_64"},"platform":"2.7.0, x86_64-linux, x86_64-pc-linux-gnu"}}} {"t":{"$date":"2020-04-13T20:42:54.572-04:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59","msg":"connection ended","attr":{"remote":"127.0.0.1:54986","connectionCount":9}} When a client connects to the server and the server shuts down (I used shutdown:1 command), it appears that the server is not creating a corresponding log entry for the connections being closed. For example, in https://gist.github.com/p-mongo/a6976d218e2eb1140b1bac0f95415306 there is no log entry for closing conn136. I expected the server to log all connection closures, whether those are initiated by the client or the server.
oleg.pudeyev commented on Fri, 24 Apr 2020 02:53:02 +0000: Thank you for the explanation. jason.carey commented on Fri, 24 Apr 2020 01:53:12 +0000: The problem is that there is no single coherent view point observing the difference between set 1 and set 2. After we kill all operations, all the various client threads will, at some point, discover they've been interrupted and begin unwinding their stacks. These stacks are unwound by separate threads that perform no synchronizing operations on close. So the shutting down thread, which is racing towards quickExit, has no idea how many sockets have already been closed and/or have logged. And the threads themselves have no idea if they're going to manage to close their sockets, or if the OS will do it for them. To provide what you're asking for would involve either: 1. handling all socket closures from the shutdown thread 2. synchronization around close, and effectively blocking threads from closing sockets after a certain point in global shutdown (to avoid double-closing / double logging) Unfortunately it's not an easy change. It would involve either a slower shutdown path, or substantially changing how we do socket closure on shutdown. Given competing priorities, we're not going to work on this at this time oleg.pudeyev commented on Wed, 22 Apr 2020 21:07:39 +0000: What I am saying is IF mongod behaves as follows: shutdown signal received some connections are explicitly closed (set 1) remaining connections are not explicitly closed but are left for OS to clean up automatically (set 2) AND there is a point where the server knows all members of set 2 (assuming it already knows all members of set 1 and prints log messages for those connections) THEN the server could, for each connection in set 2, print a message like "abandoning connection X". This message doesn't have to match the closure of the connection timing-wise, and these messages don't need to be produced in the order of connections being closed/cleaned up by the OS. These messages are just an indicator that the server will no longer read/write on connections, and should still be helpful as approximate lifetime indicators for users trying to debug their connection issues. jason.carey commented on Wed, 22 Apr 2020 20:23:15 +0000: Specifically during shutdown, depending on ordering, sometimes we're not manually closing these sockets. The process itself is going away and the OS is closing them for us after process death. There's not an opportunity to print a log message for connections closed in that way oleg.pudeyev commented on Tue, 21 Apr 2020 17:15:30 +0000: How about logging that a connection has been given up on and will not be further used? jason.carey commented on Tue, 21 Apr 2020 17:11:38 +0000: This isn't possible, many of those connections aren't being close by the mongo process, but instead by the operating systems
Connect to mongod from the client Shut down mongod Review mongod log for the connection