[2903] largely updated close() related log messages

providing more detailed explanations in some cases, revisiting message ID
to be more concise and appropriate.  reconsider one log level.

diff --git a/src/lib/asiodns/asiodns_messages.mes b/src/lib/asiodns/asiodns_messages.mes
index bd2f81a7dcf306bd719993f4e7f0013d2b1757c0..5f2a2642234bcf365fe1673fc04f5ece10ed2456 100644 (file)
--- a/src/lib/asiodns/asiodns_messages.mes
+++ b/src/lib/asiodns/asiodns_messages.mes
@@ -53,10 +53,10 @@ The asynchronous I/O code encountered an error when trying to send data to
 the specified address on the given protocol.  The number of the system
 error that caused the problem is given in the message.
 
-% ASIODNS_SYNC_UDP_CLOSE_SOCKET_FAIL_ON_STOP failed to close a
-This is the same to ASIODNS_UDP_CLOSE_SOCKET_FAIL_ON_STOP but happens
-on the "synchronous UDP server", mainly used for the authoritative DNS
-server daemon.
+% ASIODNS_SYNC_UDP_CLOSE_FAIL failed to close a DNS/UDP socket: %1
+This is the same to ASIODNS_UDP_CLOSE_FAIL but happens on the
+"synchronous UDP server", mainly used for the authoritative DNS server
+daemon.
 
 % ASIODNS_TCP_ACCEPT_FAIL failed to accept TCP DNS connection: %1
 Accepting a TCP connection from a DNS client failed due to an error
@@ -69,21 +69,39 @@ restrictive on this limitation, so consider adjusing the limit using
 a tool such as ulimit.  If you see other types of errors too often,
 there may be something overlooked; please file a bug report in that case.
 
+% ASIODNS_TCP_CLEANUP_CLOSE_FAIL failed to close a DNS/TCP socket on port cleanup: %1
+A TCP DNS server tried to close a TCP socket (one created on accepting
+a new connection or is already unused) as a step of cleaning up the
+corresponding listening port, but it failed to do that.  This is
+generally an unexpected event and so is logged as an error.
+See also the description of ASIODNS_TCP_CLOSE_ACCEPTOR_FAIL.
+
 % ASIODNS_TCP_CLOSE_ACCEPTOR_FAIL failed to close listening TCP socket: %1
 A TCP DNS server tried to close a listening TCP socket (for accepting
-new connections) as a step of stopping itself, but failed to do that.
-This is generally an unexpected event and so is logged as an error.
+new connections) as a step of cleaning up the corresponding listening
+port (e.g., on server shutdown or updating port configuration), but it
+failed to do that.  This is generally an unexpected event and so is
+logged as an error.  See ASIODNS_TCP_CLOSE_FAIL on the implication of
+related system resources.
 
 % ASIODNS_TCP_CLOSE_FAIL failed to close DNS/TCP socket with a client: %1
-A TCP DNS server tried to close a TCP socket used to communicate with a
-client, but it failed to do that.  This is expected to be very rare but
-we've seen it in real deployment.
-
-% ASIODNS_TCP_CLOSE_SOCKET_FAIL_ON_STOP failed to close a DNS/TCP socket while stopping the server: %1
-A TCP DNS server tried to close a TCP socket (which is either actively
-communicating with a client or is already unused) as a step of
-stopping itself, but failed to do that.  This is generally an
-unexpected event and so is logged as an error.
+A TCP DNS server tried to close a TCP socket used to communicate with
+a client, but it failed to do that.  While closing a socket should
+normally be an error-free operation, there have been known cases where
+this happened with a "connection reset by peer" error.  This might be
+because of some odd client behavior, such as sending a TCP RST after
+establishing the connection and before the server closes the socket,
+but how exactly this could happen seems to be system dependent (i.e,
+it's not part of the standard socket API), so it's difficult to
+provide a general explanation.  In any case, it is believed that an
+error on closing a socket doesn't mean leaking system resources (the
+kernel should clean up any internal resource related to the socket,
+just reporting an error detected in the close call), but, again, it
+seems to be system dependent.  This message is logged at a debug level
+as it's known to happen and could be triggered by a remote node and it
+would be better to not be too verbose, but you might want to increase
+the log level and make sure there's no resource leak or other system
+level troubles when it's logged.
 
 % ASIODNS_TCP_GETREMOTE_FAIL failed to get remote address of a DNS TCP connection: %1
 A TCP DNS server tried to get the address and port of a remote client
@@ -118,10 +136,9 @@ If you see a single occurrence of this message, it probably does not
 indicate any significant problem, but if it is logged often, it is probably
 a good idea to inspect your network traffic.
 
-% ASIODNS_UDP_CLOSE_SOCKET_FAIL_ON_STOP failed to close a DNS/UDP socket while stopping the server: %1
-A UDP DNS server tried to close its UDP socket as a step of stopping
-itself, but failed to do that.  This is generally an unexpected event
-and so is logged as an error.
+% ASIODNS_UDP_CLOSE_FAIL failed to close a DNS/UDP socket: %1
+A UDP DNS server tried to close its UDP socket, but failed to do that.
+This is generally an unexpected event and so is logged as an error.
 
 % ASIODNS_UDP_RECEIVE_FAIL failed to receive UDP DNS packet: %1
 Receiving a UDP packet from a DNS client failed due to an error that

diff --git a/src/lib/asiodns/sync_udp_server.cc b/src/lib/asiodns/sync_udp_server.cc
index c511014068b28458ea87d8c0ee59a6be455b8345..79c0ba4fc6f426f360e69d0bf866583b49218df6 100644 (file)
--- a/src/lib/asiodns/sync_udp_server.cc
+++ b/src/lib/asiodns/sync_udp_server.cc
@@ -151,8 +151,7 @@ SyncUDPServer::stop() {
     socket_->close(ec_);
     stopped_ = true;
     if (ec_) {
-        LOG_ERROR(logger, ASIODNS_SYNC_UDP_CLOSE_SOCKET_FAIL_ON_STOP).
-            arg(ec_.message());
+        LOG_ERROR(logger, ASIODNS_SYNC_UDP_CLOSE_FAIL).arg(ec_.message());
     }
 }
 

diff --git a/src/lib/asiodns/tcp_server.cc b/src/lib/asiodns/tcp_server.cc
index 5f2b08a1beb70e6dbdd23cab2149f7fc021a30ba..32a43ce65d4ec600d70d836edee3a922baf4204d 100644 (file)
--- a/src/lib/asiodns/tcp_server.cc
+++ b/src/lib/asiodns/tcp_server.cc
@@ -268,9 +268,8 @@ TCPServer::operator()(asio::error_code ec, size_t length) {
         socket_->close(ec);
         if (ec) {
             // close() should be unlikely to fail, but we've seen it fail once,
-            // so we log the event.
-            LOG_DEBUG(logger, DBGLVL_TRACE_BASIC, ASIODNS_TCP_CLOSE_FAIL).
-                arg(ec.message());
+            // so we log the event (at the lowest level of debug).
+            LOG_DEBUG(logger, 0, ASIODNS_TCP_CLOSE_FAIL).arg(ec.message());
         }
     }
 }
@@ -299,8 +298,7 @@ void TCPServer::stop() {
     if (socket_) {
         socket_->close(ec);
         if (ec) {
-            LOG_ERROR(logger, ASIODNS_TCP_CLOSE_SOCKET_FAIL_ON_STOP).
-                arg(ec.message());
+            LOG_ERROR(logger, ASIODNS_TCP_CLEANUP_CLOSE_FAIL).arg(ec.message());
         }
     }
 }

diff --git a/src/lib/asiodns/udp_server.cc b/src/lib/asiodns/udp_server.cc
index 2a3e3b1954b10032ff277dfd8f9051fcfeff4c33..72212969cde4ff5728c50f57775d0649d037b62d 100644 (file)
--- a/src/lib/asiodns/udp_server.cc
+++ b/src/lib/asiodns/udp_server.cc
@@ -339,8 +339,7 @@ UDPServer::stop() {
     //  get bad_descriptor error.
     data_->socket_->close(ec);
     if (ec) {
-        LOG_ERROR(logger, ASIODNS_UDP_CLOSE_SOCKET_FAIL_ON_STOP).
-            arg(ec.message());
+        LOG_ERROR(logger, ASIODNS_UDP_CLOSE_FAIL).arg(ec.message());
     }
 }