BIND 10 trac2903, updated. e4390d4f07ed2af66782abfa41ecfdbd7b1966cd [2903] largely updated close() related log messages

BIND 10 source code commits bind10-changes at lists.isc.org
Tue Apr 30 18:35:24 UTC 2013


The branch, trac2903 has been updated
       via  e4390d4f07ed2af66782abfa41ecfdbd7b1966cd (commit)
      from  7ba811ceb844372d04d8f0ca62f112a377889ae9 (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.

- Log -----------------------------------------------------------------
commit e4390d4f07ed2af66782abfa41ecfdbd7b1966cd
Author: JINMEI Tatuya <jinmei at isc.org>
Date:   Tue Apr 30 11:21:16 2013 -0700

    [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.

-----------------------------------------------------------------------

Summary of changes:
 src/lib/asiodns/asiodns_messages.mes |   55 ++++++++++++++++++++++------------
 src/lib/asiodns/sync_udp_server.cc   |    3 +-
 src/lib/asiodns/tcp_server.cc        |    8 ++---
 src/lib/asiodns/udp_server.cc        |    3 +-
 4 files changed, 41 insertions(+), 28 deletions(-)

-----------------------------------------------------------------------
diff --git a/src/lib/asiodns/asiodns_messages.mes b/src/lib/asiodns/asiodns_messages.mes
index bd2f81a..5f2a264 100644
--- 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 c511014..79c0ba4 100644
--- 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 5f2b08a..32a43ce 100644
--- 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 2a3e3b1..7221296 100644
--- 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());
     }
 }
 



More information about the bind10-changes mailing list