[3880] Changes after review:

 - Extra logging messages for socket failures
 - strerror() is now reported when encountering low-level errors
 - fcntl, accept return codes are now verified
 - minor tweaks in CtrlDhcpv4SrvTest.command* unit-tests.

src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc

@@ -101,7 +101,8 @@ public:
         // Connect to the specified UNIX socket
         int status = connect(socket_fd, (struct sockaddr*)&srv_addr, len);
         if (status == -1) {
-            ADD_FAILURE() << "Failed to connect socket";
+            ADD_FAILURE() << "Failed to connect unix socket: fd=" << socket_fd
+                          << ", path=" << socket_path;
             close(socket_fd);
             return (false);
         }
@@ -274,6 +275,7 @@ TEST_F(CtrlDhcpv4SrvTest, commandsRegistration) {
 TEST_F(CtrlDhcpv4SrvTest, DISABLED_commandSocketBasic) {
 
     string socket_path = string(TEST_DATA_DIR) + "/kea4.sock";
+    ::remove(socket_path.c_str());
 
     // Just a simple config. The important part here is the socket
     // location information.

src/lib/config/command_mgr.cc

@@ -129,6 +129,8 @@ void CommandMgr::deregisterAll() {
 void
 CommandMgr::commandReader(int sockfd) {
 
+    /// @todo: We do not handle commands that are larger than 64K.
+
     // We should not expect commands bigger than 64K.
     char buf[65536];
     memset(buf, 0, sizeof(buf));
@@ -162,7 +164,7 @@ CommandMgr::commandReader(int sockfd) {
         // If successful, then process it as a command.
         rsp = CommandMgr::instance().processCommand(cmd);
     } catch (const Exception& ex) {
-        LOG_WARN(command_logger, COMMAND_PROCESS_ERROR).arg(ex.what());
+        LOG_WARN(command_logger, COMMAND_PROCESS_ERROR1).arg(ex.what());
         rsp = createAnswer(CONTROL_RESULT_ERROR, std::string(ex.what()));
     }
 
@@ -178,6 +180,8 @@ CommandMgr::commandReader(int sockfd) {
     if (len > 65535) {
         // Hmm, our response is too large. Let's send the first
         // 64KB and hope for the best.
+        LOG_WARN(command_logger, COMMAND_SOCKET_RESPONSE_TOOLARGE).arg(len);
+
         len = 65535;
     }
 
@@ -218,6 +222,7 @@ CommandMgr::processCommand(const isc::data::ConstElementPtr& cmd) {
         return (it->second(name, arg));
 
     } catch (const Exception& e) {
+        LOG_WARN(command_logger, COMMAND_PROCESS_ERROR2).arg(e.what());
         return (createAnswer(CONTROL_RESULT_ERROR,
                              std::string("Error during command processing:")
                              + e.what()));

src/lib/config/command_socket_factory.cc

@@ -20,6 +20,7 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 #include <string.h>
+#include <errno.h>
 #include <cstdio>
 #include <fcntl.h>
 
@@ -79,7 +80,10 @@ private:
         remove(file_name.c_str());
 
         // Set this socket to be non-blocking one.
-        fcntl(fd, F_SETFL, O_NONBLOCK);
+        if (fcntl(fd, F_SETFL, O_NONBLOCK) !=0 ) {
+            isc_throw(SocketError, "Failed to set non-block mode on unix socket "
+                      << fd << ": " << strerror(errno));
+        }
 
         // Now bind the socket to the specified path.
         struct sockaddr_un addr;
@@ -90,7 +94,7 @@ private:
             ::close(fd);
             remove(file_name.c_str());
             isc_throw(isc::config::SocketError, "Failed to bind socket " << fd
-                      << " to " << file_name);
+                      << " to " << file_name << ": " << strerror(errno));
         }
 
         // One means that we allow at most 1 awaiting connections.
@@ -103,7 +107,8 @@ private:
             ::close(fd);
             remove(file_name.c_str());
             isc_throw(isc::config::SocketError, "Failed to listen on socket fd="
-                      << fd << ", filename=" << file_name);
+                      << fd << ", filename=" << file_name << ": "
+                      << strerror(errno));
         }
 
         // Woohoo! Socket opened, let's log it!
@@ -128,15 +133,27 @@ private:
 
         // Accept incoming connection. This will create a separate socket for
         // handling this specific connection.
-        int fd2 = accept(sockfd_, static_cast<struct sockaddr*>(&client_addr),
+        int fd2 = accept(sockfd_, reinterpret_cast<struct sockaddr*>(&client_addr),
                          &client_addr_len);
+        if (fd2 == -1) {
+            LOG_ERROR(command_logger, COMMAND_SOCKET_ACCEPT_FAIL)
+                .arg(sockfd_).arg(strerror(errno));
+            return;
+        }
 
         // And now create an object that represents that new connection.
         CommandSocketPtr conn(new ConnectionSocket(fd2));
 
         // Not sure if this is really needed, but let's set it to non-blocking
         // mode.
-        fcntl(fd2, F_SETFL, O_NONBLOCK);
+        if (fcntl(fd2, F_SETFL, O_NONBLOCK) != 0) {
+            // Failed to set socket to non-blocking mode.
+            LOG_ERROR(command_logger, COMMAND_SOCKET_FAIL_NONBLOCK)
+                .arg(fd2).arg(sockfd_).arg(strerror(errno));
+
+            conn.reset();
+            return;
+        }
 
         // Remember this socket descriptor. It will be needed when we shut down
         // the server.
@@ -153,10 +170,13 @@ private:
 
         isc::dhcp::IfaceMgr::instance().deleteExternalSocket(sockfd_);
 
+        // Close should always succeed. We don't care if we're able to delete
+        // the socket or not.
         ::close(sockfd_);
         remove(filename_.c_str());
     }
 
+    /// @brief UNIX filename representing this socket
     std::string filename_;
 };
 

src/lib/config/config_messages.mes

@@ -14,11 +14,18 @@
 
 $NAMESPACE isc::config
 
-% COMMAND_PROCESS_ERROR Error while processing command: %1
+% COMMAND_PROCESS_ERROR1 Error while processing command: %1
 This warning message indicates that the server encountered an error while
 processing received command. Additional information will be provided, if
 available. Additional log messages may provide more details.
 
+% COMMAND_PROCESS_ERROR2 Error while processing command: %1
+This warning message indicates that the server encountered an error while
+processing received command. The difference, compared to COMMAND_PROCESS_ERROR1
+is that the initial command was well formed and the error occurred during
+logic processing, not the command parsing. Additional information will be
+provided, if available. Additional log messages may provide more details.
+
 % COMMAND_RECEIVED Received command '%1'
 This informational message indicates that a command was received over command
 socket. The nature of this command and its possible results will be logged
@@ -30,6 +37,16 @@ specified command. This likely indicates a server logic error, as the server
 is expected to generate valid responses for all commands, even malformed
 ones.
 
+% COMMAND_SOCKET_FAIL_NONBLOCK Failed to set non-blocking mode for socket %1 created for incoming connection on socket %2: %3
+This error message indicates that the server failed to set non-blocking mode
+on just created socket. That socket was created for accepting specific
+incoming connection. Additional information may be provided as third parameter.
+
+% COMMAND_SOCKET_ACCEPT_FAIL Failed to accept incoming connection on command socket %1: %2
+This error indicates that the server detected incoming connection and executed
+accept system call on said socket, but this call returned an error. Additional
+information may be provided by the system as second parameter.
+
 % COMMAND_SOCKET_READ Received %1 bytes over command socket %2
 This debug message indicates that specified number of bytes was received
 over command socket identified by specified file descriptor.
@@ -42,6 +59,13 @@ reading from command socket.
 This debug message indicates that the specified number of bytes was sent
 over command socket identifier by the specified file descriptor.
 
+% COMMAND_SOCKET_RESPONSE_TOOLARGE Server's response was larger (%1) than supported 64KB
+This warning message indicates that the server received a command and generated
+an answer for it, but that response was larger than supported 64KB. Server
+will attempt to send the first 64KB of the response. Depending on the nature
+of this response, this may indicate a software or configuration error. Future
+Kea versions are expected to have better support for large responses.
+
 % COMMAND_SOCKET_WRITE_FAIL Error while writing %1 bytes to command socket %2
 This warning message indicates that an error was encountered while
 attempting to send a response to the command socket.