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

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.

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) {

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

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()) {