Browse Source

[5318] Cleanup comments and log messages in the CommandMgr.

Marcin Siodelski 7 years ago
parent
commit
5d68c24bff
2 changed files with 58 additions and 61 deletions
  1. 52 38
      src/lib/config/command_mgr.cc
  2. 6 23
      src/lib/config/config_messages.mes

+ 52 - 38
src/lib/config/command_mgr.cc

@@ -27,6 +27,9 @@ using namespace isc::data;
 
 
 namespace {
 namespace {
 
 
+/// @brief Maximum size of the data chunk sent/received over the socket.
+const size_t BUF_SIZE = 8192;
+
 class ConnectionPool;
 class ConnectionPool;
 
 
 /// @brief Represents a single connection over control socket.
 /// @brief Represents a single connection over control socket.
@@ -41,10 +44,19 @@ public:
     /// This constructor registers a socket of this connection in the Interface
     /// This constructor registers a socket of this connection in the Interface
     /// Manager to cause the blocking call to @c select() to return as soon as
     /// Manager to cause the blocking call to @c select() to return as soon as
     /// a transmission over the control socket is received.
     /// a transmission over the control socket is received.
+    ///
+    /// @param socket Pointer to the object representing a socket which is used
+    /// for data transmission.
+    /// @param connection_pool Reference to the connection pool to which this
+    /// connection belongs.
     Connection(const boost::shared_ptr<UnixDomainSocket>& socket,
     Connection(const boost::shared_ptr<UnixDomainSocket>& socket,
                ConnectionPool& connection_pool)
                ConnectionPool& connection_pool)
         : socket_(socket), buf_(), response_(), connection_pool_(connection_pool),
         : socket_(socket), buf_(), response_(), connection_pool_(connection_pool),
           feed_(), response_in_progress_(false) {
           feed_(), response_in_progress_(false) {
+
+        LOG_INFO(command_logger, COMMAND_SOCKET_CONNECTION_OPENED)
+            .arg(socket_->getNative());
+
         // Callback value of 0 is used to indicate that callback function is
         // Callback value of 0 is used to indicate that callback function is
         // not installed.
         // not installed.
         isc::dhcp::IfaceMgr::instance().addExternalSocket(socket_->getNative(), 0);
         isc::dhcp::IfaceMgr::instance().addExternalSocket(socket_->getNative(), 0);
@@ -86,7 +98,7 @@ public:
     /// This method doesn't block. Once the send operation is completed, the
     /// This method doesn't block. Once the send operation is completed, the
     /// @c Connection::sendHandler cllback is invoked.
     /// @c Connection::sendHandler cllback is invoked.
     void doSend() {
     void doSend() {
-        size_t chunk_size = response_.size() < 8192 ? response_.size() : 8192;
+        size_t chunk_size = (response_.size() < BUF_SIZE) ? response_.size() : BUF_SIZE;
         socket_->asyncSend(&response_[0], chunk_size,
         socket_->asyncSend(&response_[0], chunk_size,
            boost::bind(&Connection::sendHandler, shared_from_this(), _1, _2));
            boost::bind(&Connection::sendHandler, shared_from_this(), _1, _2));
     }
     }
@@ -112,7 +124,7 @@ private:
     boost::shared_ptr<UnixDomainSocket> socket_;
     boost::shared_ptr<UnixDomainSocket> socket_;
 
 
     /// @brief Buffer used for received data.
     /// @brief Buffer used for received data.
-    std::array<char, 65535> buf_;
+    std::array<char, BUF_SIZE> buf_;
 
 
     /// @brief Response created by the server.
     /// @brief Response created by the server.
     std::string response_;
     std::string response_;
@@ -149,8 +161,13 @@ public:
     ///
     ///
     /// @param connection Pointer to the new connection object.
     /// @param connection Pointer to the new connection object.
     void stop(const ConnectionPtr& connection) {
     void stop(const ConnectionPtr& connection) {
-        connection->stop();
+        try {
-        connections_.erase(connection);
+            connection->stop();
+            connections_.erase(connection);
+        } catch (const std::exception& ex) {
+            LOG_ERROR(command_logger, COMMAND_SOCKET_CONNECTION_CLOSE_FAIL)
+                .arg(ex.what());
+        }
     }
     }
 
 
     /// @brief Stops all connections which are allowed to stop.
     /// @brief Stops all connections which are allowed to stop.
@@ -162,10 +179,6 @@ public:
         connections_.clear();
         connections_.clear();
     }
     }
 
 
-    size_t getConnectionsNum() const {
-        return (connections_.size());
-    }
-
 private:
 private:
 
 
     /// @brief Pool of connections.
     /// @brief Pool of connections.
@@ -183,15 +196,13 @@ Connection::receiveHandler(const boost::system::error_code& ec,
             // connection pool.
             // connection pool.
             LOG_INFO(command_logger, COMMAND_SOCKET_CLOSED_BY_FOREIGN_HOST)
             LOG_INFO(command_logger, COMMAND_SOCKET_CLOSED_BY_FOREIGN_HOST)
                 .arg(socket_->getNative());
                 .arg(socket_->getNative());
-            connection_pool_.stop(shared_from_this());
 
 
         } else if (ec.value() != boost::asio::error::operation_aborted) {
         } else if (ec.value() != boost::asio::error::operation_aborted) {
             LOG_ERROR(command_logger, COMMAND_SOCKET_READ_FAIL)
             LOG_ERROR(command_logger, COMMAND_SOCKET_READ_FAIL)
                 .arg(ec.value()).arg(socket_->getNative());
                 .arg(ec.value()).arg(socket_->getNative());
         }
         }
 
 
-        /// @todo: Should we close the connection, similar to what is already
+        connection_pool_.stop(shared_from_this());
-        /// being done for bytes_transferred == 0.
         return;
         return;
 
 
     } else if (bytes_transferred == 0) {
     } else if (bytes_transferred == 0) {
@@ -203,19 +214,22 @@ Connection::receiveHandler(const boost::system::error_code& ec,
     LOG_DEBUG(command_logger, DBG_COMMAND, COMMAND_SOCKET_READ)
     LOG_DEBUG(command_logger, DBG_COMMAND, COMMAND_SOCKET_READ)
         .arg(bytes_transferred).arg(socket_->getNative());
         .arg(bytes_transferred).arg(socket_->getNative());
 
 
-    ConstElementPtr cmd, rsp;
+    ConstElementPtr rsp;
 
 
     try {
     try {
-
+        // Received some data over the socket. Append them to the JSON feed
+        // to see if we have reached the end of command.
         feed_.postBuffer(&buf_[0], bytes_transferred);
         feed_.postBuffer(&buf_[0], bytes_transferred);
         feed_.poll();
         feed_.poll();
+        // If we haven't yet received the full command, continue receiving.
         if (feed_.needData()) {
         if (feed_.needData()) {
             doReceive();
             doReceive();
             return;
             return;
         }
         }
 
 
+        // Received entire command. Parse the command into JSON.
         if (feed_.feedOk()) {
         if (feed_.feedOk()) {
-            cmd = feed_.toElement();
+            ConstElementPtr cmd = feed_.toElement();
             response_in_progress_ = true;
             response_in_progress_ = true;
 
 
             // If successful, then process it as a command.
             // If successful, then process it as a command.
@@ -224,6 +238,9 @@ Connection::receiveHandler(const boost::system::error_code& ec,
             response_in_progress_ = false;
             response_in_progress_ = false;
 
 
         } else {
         } else {
+            // Failed to parse command as JSON or process the received command.
+            // This exception will be caught below and the error response will
+            // be sent.
             isc_throw(BadValue, feed_.getErrorMessage());
             isc_throw(BadValue, feed_.getErrorMessage());
         }
         }
 
 
@@ -246,46 +263,39 @@ Connection::receiveHandler(const boost::system::error_code& ec,
 
 
         doSend();
         doSend();
         return;
         return;
-
-/*        size_t len = response_.length();
-        if (len > 65535) {
-            // Hmm, our response is too large. Let's send the first
-            // 64KB and hope for the best.
-            LOG_ERROR(command_logger, COMMAND_SOCKET_RESPONSE_TOOLARGE).arg(len);
-
-            len = 65535;
-        }
-
-        try {
-            // Send the data back over socket.
-            socket_->write(response_.c_str(), len);
-
-        } catch (const std::exception& ex) {
-            // Response transmission failed. Since the response failed, it doesn't
-            // make sense to send any status codes. Let's log it and be done with
-            // it.
-            LOG_ERROR(command_logger, COMMAND_SOCKET_WRITE_FAIL)
-                .arg(len).arg(socket_->getNative()).arg(ex.what());
-        } */
     }
     }
 
 
+    // Close the connection if we have sent the entire response.
     connection_pool_.stop(shared_from_this());
     connection_pool_.stop(shared_from_this());
 }
 }
 
 
 void
 void
 Connection::sendHandler(const boost::system::error_code& ec,
 Connection::sendHandler(const boost::system::error_code& ec,
                         size_t bytes_transferred) {
                         size_t bytes_transferred) {
-    if (ec && ec.value() != boost::asio::error::operation_aborted) {
+    if (ec) {
-        LOG_ERROR(command_logger, COMMAND_SOCKET_WRITE_FAIL)
+        // If an error occurred, log this error and stop the connection.
-            .arg(socket_->getNative()).arg(ec.message());
+        if (ec.value() != boost::asio::error::operation_aborted) {
+            LOG_ERROR(command_logger, COMMAND_SOCKET_WRITE_FAIL)
+                .arg(socket_->getNative()).arg(ec.message());
+        }
 
 
     } else {
     } else {
+
+        LOG_DEBUG(command_logger, DBG_COMMAND, COMMAND_SOCKET_WRITE)
+            .arg(bytes_transferred).arg(socket_->getNative());
+
+        // No error. We are in a process of sending a response. Need to
+        // remove the chunk that we have managed to sent with the previous
+        // attempt.
         response_.erase(0, bytes_transferred);
         response_.erase(0, bytes_transferred);
+        // Check if there is any data left to be sent and sent it.
         if (!response_.empty()) {
         if (!response_.empty()) {
             doSend();
             doSend();
             return;
             return;
+        }
     }
     }
 
 
+    // All data sent or an error has occurred. Close the connection.
     connection_pool_.stop(shared_from_this());
     connection_pool_.stop(shared_from_this());
 }
 }
 
 
@@ -392,6 +402,10 @@ CommandMgrImpl::doAccept() {
             // New connection is arriving. Start asynchronous transmission.
             // New connection is arriving. Start asynchronous transmission.
             ConnectionPtr connection(new Connection(socket_, connection_pool_));
             ConnectionPtr connection(new Connection(socket_, connection_pool_));
             connection_pool_.start(connection);
             connection_pool_.start(connection);
+
+        } else if (ec.value() != boost::asio::error::operation_aborted) {
+            LOG_ERROR(command_logger, COMMAND_SOCKET_ACCEPT_FAIL)
+                .arg(acceptor_->getNative()).arg(ec.message());
         }
         }
 
 
         // Unless we're stopping the service, start accepting connections again.
         // Unless we're stopping the service, start accepting connections again.

+ 6 - 23
src/lib/config/config_messages.mes

@@ -64,22 +64,15 @@ This is an informational message that the socket created for handling
 client's connection is closed. This usually means that the client disconnected,
 client's connection is closed. This usually means that the client disconnected,
 but may also mean a timeout.
 but may also mean a timeout.
 
 
-% COMMAND_SOCKET_CONNECTION_OPENED Opened socket %1 for incoming command connection on socket %2
+% COMMAND_SOCKET_CONNECTION_CLOSE_FAIL Failed to close command connection: %1
+This error message is issued when an error occurred when closing a
+command connection and/or removing it from the connections pool. The
+detailed error is provided as an argument.
+
+% COMMAND_SOCKET_CONNECTION_OPENED Opened socket %1 for incoming command connection
 This is an informational message that a new incoming command connection was
 This is an informational message that a new incoming command connection was
 detected and a dedicated socket was opened for that connection.
 detected and a dedicated socket was opened for that connection.
 
 
-% COMMAND_SOCKET_DUP_WARN Failed to duplicate socket for response: %1
-This debug message indicates that the commandReader was unable to duplicate
-the connection socket prior to executing the command. This is most likely a
-system resource issue.  The command should still be processed and the response
-sent, unless the command caused the command channel to be closed (e.g. a
-reconfiguration command).
-
-% 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_READ Received %1 bytes over command socket %2
 % COMMAND_SOCKET_READ Received %1 bytes over command socket %2
 This debug message indicates that specified number of bytes was received
 This debug message indicates that specified number of bytes was received
 over command socket identified by specified file descriptor.
 over command socket identified by specified file descriptor.
@@ -88,16 +81,6 @@ over command socket identified by specified file descriptor.
 This error message indicates that an error was encountered while
 This error message indicates that an error was encountered while
 reading from command socket.
 reading from command socket.
 
 
-% COMMAND_SOCKET_UNIX_CLOSE Command socket closed: UNIX, fd=%1, path=%2
-This informational message indicates that the daemon closed a command
-processing socket. This was a UNIX socket. It was opened with the file
-descriptor and path specified.
-
-% COMMAND_SOCKET_UNIX_OPEN Command socket opened: UNIX, fd=%1, path=%2
-This informational message indicates that the daemon opened a command
-processing socket. This is a UNIX socket. It was opened with the file
-descriptor and path specified.
-
 % COMMAND_SOCKET_WRITE Sent response of %1 bytes over command socket %2
 % COMMAND_SOCKET_WRITE Sent response of %1 bytes over command socket %2
 This debug message indicates that the specified number of bytes was sent
 This debug message indicates that the specified number of bytes was sent
 over command socket identifier by the specified file descriptor.
 over command socket identifier by the specified file descriptor.