BIND 10 trac3221, updated. 2ca54a3ed0a89b2b90a10e2cc80bed218ae8607c [3221] Improved WatchSocket error handling in dhcp_ddns::NameChangeUDPSender

BIND 10 source code commits bind10-changes at lists.isc.org
Mon Feb 10 16:48:52 UTC 2014


The branch, trac3221 has been updated
       via  2ca54a3ed0a89b2b90a10e2cc80bed218ae8607c (commit)
      from  a080f7b48a4895a5dfbee3690de6cc2881f123cd (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 2ca54a3ed0a89b2b90a10e2cc80bed218ae8607c
Author: Thomas Markwalder <tmark at isc.org>
Date:   Mon Feb 10 11:45:58 2014 -0500

    [3221] Improved WatchSocket error handling in dhcp_ddns::NameChangeUDPSender
    
    Shored up the error handling in the sender when the WatchSocket fails to mark
    or clear. Addes unit tests accordingly.

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

Summary of changes:
 src/lib/dhcp_ddns/dhcp_ddns_messages.mes     |   10 +-
 src/lib/dhcp_ddns/ncr_udp.cc                 |   17 +++-
 src/lib/dhcp_ddns/tests/ncr_udp_unittests.cc |  132 +++++++++++++++++++++++++-
 src/lib/dhcp_ddns/watch_socket.cc            |    8 +-
 4 files changed, 160 insertions(+), 7 deletions(-)

-----------------------------------------------------------------------
diff --git a/src/lib/dhcp_ddns/dhcp_ddns_messages.mes b/src/lib/dhcp_ddns/dhcp_ddns_messages.mes
index c5f6f7d..fa28354 100644
--- a/src/lib/dhcp_ddns/dhcp_ddns_messages.mes
+++ b/src/lib/dhcp_ddns/dhcp_ddns_messages.mes
@@ -32,14 +32,14 @@ start another read after receiving a request.  While possible, this is highly
 unlikely and is probably a programmatic error.  The application should recover
 on its own.
 
-% DHCP_DDNS_NCR_SEND_CLOSE_ERROR DHCP-DDNS client encountered an error while closing the sender connection used to send NameChangeRequests : %1
+% DHCP_DDNS_NCR_SEND_CLOSE_ERROR DHCP-DDNS client encountered an error while closing the sender connection used to send NameChangeRequests: %1
 This is an error message that indicates the DHCP-DDNS client was unable to
 close the connection used to send NameChangeRequests.  Closure may occur during
 the course of error recovery or during normal shutdown procedure.  In either
 case the error is unlikely to impair the client's ability to send requests but
 it should be reported for analysis.
 
-% DHCP_DDNS_NCR_SEND_NEXT_ERROR DHCP-DDNS client could not initiate the next request send following send completion.
+% DHCP_DDNS_NCR_SEND_NEXT_ERROR DHCP-DDNS client could not initiate the next request send following send completion: %1
 This is a error message indicating that NameChangeRequest sender could not
 start another send after completing the send of the previous request.  While
 possible, this is highly unlikely and is probably a programmatic error.  The
@@ -86,3 +86,9 @@ This is an error message that indicates the application was unable to close
 the inbound side of a NCR sender's watch socket.  While technically possible
 this error is highly unlikely to occur and should not impair the application's
 ability to process requests.
+
+% DHCP_DDNS_NCR_UDP_CLEAR_READY_ERROR NCR UPD watch socket failed to clear: %1
+This is an error message that indicates the application was unable to reset the
+UDP NCR sender ready status after completing a send.  This is programmatic error
+that should be reported.  The application may or may not continue to operator
+correctly.
diff --git a/src/lib/dhcp_ddns/ncr_udp.cc b/src/lib/dhcp_ddns/ncr_udp.cc
index 3906c9b..d68d1f8 100644
--- a/src/lib/dhcp_ddns/ncr_udp.cc
+++ b/src/lib/dhcp_ddns/ncr_udp.cc
@@ -304,6 +304,10 @@ NameChangeUDPSender::doSend(NameChangeRequestPtr& ncr) {
                        send_callback_->getDataSource().get(), *send_callback_);
 
     // Set IO ready marker so sender activity is visible to select() or poll().
+    // Note, if this call throws it will manifest itself as a throw from
+    // from sendRequest() which the application calls directly and is documented
+    // as throwing exceptions; or caught inside invokeSendHandler() which
+    // will invoke the application's send_handler with an error status.
     watch_socket_->markReady();
 }
 
@@ -311,7 +315,18 @@ void
 NameChangeUDPSender::sendCompletionHandler(const bool successful,
                                            const UDPCallback *send_callback) {
     // Clear the IO ready marker.
-    watch_socket_->clearReady();
+    try {
+        watch_socket_->clearReady();
+    } catch (const std::exception& ex) {
+        // This can only happen if the WatchSocket's select_fd has been
+        // compromised which is a programmatic error. We'll log the error
+        // here, then continue on and process the IO result we were given.
+        // WatchSocket issue will resurface on the next send as a closed
+        // fd in markReady().  This allows application's handler to deal
+        // with watch errors more uniformly.
+        LOG_ERROR(dhcp_ddns_logger, DHCP_DDNS_NCR_UDP_CLEAR_READY_ERROR)
+                 .arg(ex.what());
+    }
 
     Result result;
     if (successful) {
diff --git a/src/lib/dhcp_ddns/tests/ncr_udp_unittests.cc b/src/lib/dhcp_ddns/tests/ncr_udp_unittests.cc
index 7ea4b49..835afaf 100644
--- a/src/lib/dhcp_ddns/tests/ncr_udp_unittests.cc
+++ b/src/lib/dhcp_ddns/tests/ncr_udp_unittests.cc
@@ -272,9 +272,20 @@ TEST_F(NameChangeUDPListenerTest, basicReceivetest) {
 /// @brief A NOP derivation for constructor test purposes.
 class SimpleSendHandler : public NameChangeSender::RequestSendHandler {
 public:
-    virtual void operator ()(const NameChangeSender::Result,
+    SimpleSendHandler() : pass_count_(0), error_count_(0) {
+    }
+
+    virtual void operator ()(const NameChangeSender::Result result,
                              NameChangeRequestPtr&) {
+        if (result == NameChangeSender::SUCCESS) {
+            ++pass_count_;
+        } else {
+            ++error_count_;
+        }
     }
+
+    int pass_count_;
+    int error_count_;
 };
 
 /// @brief Tests the NameChangeUDPSender constructors.
@@ -649,4 +660,123 @@ TEST_F (NameChangeUDPTest, roundTripTest) {
     EXPECT_FALSE(sender_->amSending());
 }
 
+// Tests error handling of a failure to mark the watch socket ready, when
+// sendRequestt() is called.
+TEST(NameChangeUDPSenderBasicTest, watchClosedBeforeSendRequest) {
+    isc::asiolink::IOAddress ip_address(TEST_ADDRESS);
+    isc::asiolink::IOService io_service;
+    SimpleSendHandler ncr_handler;
+
+    // Create the sender and put into send mode.
+    NameChangeUDPSender sender(ip_address, 0, ip_address, LISTENER_PORT,
+                               FMT_JSON, ncr_handler, 100, true);
+    ASSERT_NO_THROW(sender.startSending(io_service));
+    ASSERT_TRUE(sender.amSending());
+
+    // Create an NCR.
+    NameChangeRequestPtr ncr;
+    ASSERT_NO_THROW(ncr = NameChangeRequest::fromJSON(valid_msgs[0]));
+
+    // Tamper with the watch socket by closing the select-fd.
+    close(sender.getSelectFd());
+
+    // Send should fail as we interferred by closing the select-fd.
+    ASSERT_THROW(sender.sendRequest(ncr), WatchSocketError);
+
+    // Verify we didn't invoke the handler.
+    EXPECT_EQ(0, ncr_handler.pass_count_);
+    EXPECT_EQ(0, ncr_handler.error_count_);
+
+    // Request remains in the queue. Technically it was sent but its
+    // completion handler won't get called.
+    EXPECT_EQ(1, sender.getQueueSize());
+}
+
+// Tests error handling of a failure to mark the watch socket ready, when
+// sendNext() is called during completion handling.
+TEST(NameChangeUDPSenderBasicTest, watchClosedAfterSendRequest) {
+    isc::asiolink::IOAddress ip_address(TEST_ADDRESS);
+    isc::asiolink::IOService io_service;
+    SimpleSendHandler ncr_handler;
+
+    // Create the sender and put into send mode.
+    NameChangeUDPSender sender(ip_address, 0, ip_address, LISTENER_PORT,
+                               FMT_JSON, ncr_handler, 100, true);
+    ASSERT_NO_THROW(sender.startSending(io_service));
+    ASSERT_TRUE(sender.amSending());
+
+    // Build and queue up 2 messages.  No handlers will get called yet.
+    for (int i = 0; i < 2; i++) {
+        NameChangeRequestPtr ncr;
+        ASSERT_NO_THROW(ncr = NameChangeRequest::fromJSON(valid_msgs[i]));
+        sender.sendRequest(ncr);
+        EXPECT_EQ(i+1, sender.getQueueSize());
+    }
+
+    // Tamper with the watch socket by closing the select-fd.
+    close (sender.getSelectFd());
+
+    // Run one handler. This should execute the send completion handler
+    // after sending the first message.  Duing completion handling, we will
+    // attempt to queue the second message which should fail.
+    ASSERT_NO_THROW(io_service.run_one());
+
+    // Verify handler got called twice. First request should have be sent
+    // without error, second call should have failed to send due to watch
+    // socket markReady failure.
+    EXPECT_EQ(1, ncr_handler.pass_count_);
+    EXPECT_EQ(1, ncr_handler.error_count_);
+
+    // The second request should still be in the queue.
+    EXPECT_EQ(1, sender.getQueueSize());
+}
+
+// Tests error handling of a failure to clear the watch socket during
+// completion handling.
+TEST(NameChangeUDPSenderBasicTest, watchSocketBadRead) {
+    isc::asiolink::IOAddress ip_address(TEST_ADDRESS);
+    isc::asiolink::IOService io_service;
+    SimpleSendHandler ncr_handler;
+
+    // Create the sender and put into send mode.
+    NameChangeUDPSender sender(ip_address, 0, ip_address, LISTENER_PORT,
+                               FMT_JSON, ncr_handler, 100, true);
+    ASSERT_NO_THROW(sender.startSending(io_service));
+    ASSERT_TRUE(sender.amSending());
+
+    // Build and queue up 2 messages.  No handlers will get called yet.
+    for (int i = 0; i < 2; i++) {
+        NameChangeRequestPtr ncr;
+        ASSERT_NO_THROW(ncr = NameChangeRequest::fromJSON(valid_msgs[i]));
+        sender.sendRequest(ncr);
+        EXPECT_EQ(i+1, sender.getQueueSize());
+    }
+
+    // Fetch the sender's select-fd.
+    int select_fd = sender.getSelectFd();
+
+    // Verify that select_fd appears ready.
+    ASSERT_TRUE(selectCheck(select_fd) > 0);
+
+    // Interfere by reading part of the marker from the select-fd.
+    uint32_t buf = 0;
+    ASSERT_EQ((read (select_fd, &buf, 1)), 1);
+    ASSERT_NE(WatchSocket::MARKER, buf);
+
+    // Run one handler. This should execute the send completion handler
+    // after sending the message.  Duing completion handling clearing the
+    // watch socket should fail, which will close the socket, but not
+    // result in a throw.
+    ASSERT_NO_THROW(io_service.run_one());
+
+    // Verify handler got called twice. First request should have be sent
+    // without error, second call should have failed to send due to watch
+    // socket markReady failure.
+    EXPECT_EQ(1, ncr_handler.pass_count_);
+    EXPECT_EQ(1, ncr_handler.error_count_);
+
+    // The second request should still be in the queue.
+    EXPECT_EQ(1, sender.getQueueSize());
+}
+
 } // end of anonymous namespace
diff --git a/src/lib/dhcp_ddns/watch_socket.cc b/src/lib/dhcp_ddns/watch_socket.cc
index 0a437a6..fd4027e 100644
--- a/src/lib/dhcp_ddns/watch_socket.cc
+++ b/src/lib/dhcp_ddns/watch_socket.cc
@@ -53,11 +53,13 @@ WatchSocket::~WatchSocket() {
 
 void
 WatchSocket::markReady() {
-    // Make sure it hasn't been orphaned!  Otherwise we may get SIGPIPE.
-    // We use fcntl to check as select() on some systems may show it as ready to read.
+    // Make sure it hasn't been orphaned!  Otherwise we may get SIGPIPE.  We
+    // use fcntl to check as select() on some systems may show it as ready to
+    // read.
     if (fcntl(sink_, F_GETFL) < 0) {
         closeSocket();
-        isc_throw(WatchSocketError, "WatchSocket markReady - select_fd was closed!");
+        isc_throw(WatchSocketError, "WatchSocket markReady failed:"
+                  " select_fd was closed!");
     }
 
     if (!isReady()) {



More information about the bind10-changes mailing list