From 5d68c24bff453f2b44cb25d80fc77aad64abbf98 Mon Sep 17 00:00:00 2001 From: Marcin Siodelski Date: Mon, 3 Jul 2017 14:08:54 +0200 Subject: [PATCH] [5318] Cleanup comments and log messages in the CommandMgr. --- src/lib/config/command_mgr.cc | 90 +++++++++++++++++------------- src/lib/config/config_messages.mes | 29 ++-------- 2 files changed, 58 insertions(+), 61 deletions(-) diff --git a/src/lib/config/command_mgr.cc b/src/lib/config/command_mgr.cc index 2d6c249972..391966fc7d 100644 --- a/src/lib/config/command_mgr.cc +++ b/src/lib/config/command_mgr.cc @@ -27,6 +27,9 @@ using namespace isc::data; namespace { +/// @brief Maximum size of the data chunk sent/received over the socket. +const size_t BUF_SIZE = 8192; + class ConnectionPool; /// @brief Represents a single connection over control socket. @@ -41,10 +44,19 @@ public: /// 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 /// 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& socket, ConnectionPool& connection_pool) : socket_(socket), buf_(), response_(), connection_pool_(connection_pool), 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 // not installed. 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 /// @c Connection::sendHandler cllback is invoked. 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, boost::bind(&Connection::sendHandler, shared_from_this(), _1, _2)); } @@ -112,7 +124,7 @@ private: boost::shared_ptr socket_; /// @brief Buffer used for received data. - std::array buf_; + std::array buf_; /// @brief Response created by the server. std::string response_; @@ -149,8 +161,13 @@ public: /// /// @param connection Pointer to the new connection object. void stop(const ConnectionPtr& connection) { - connection->stop(); - connections_.erase(connection); + try { + 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. @@ -162,10 +179,6 @@ public: connections_.clear(); } - size_t getConnectionsNum() const { - return (connections_.size()); - } - private: /// @brief Pool of connections. @@ -183,15 +196,13 @@ Connection::receiveHandler(const boost::system::error_code& ec, // connection pool. LOG_INFO(command_logger, COMMAND_SOCKET_CLOSED_BY_FOREIGN_HOST) .arg(socket_->getNative()); - connection_pool_.stop(shared_from_this()); } else if (ec.value() != boost::asio::error::operation_aborted) { LOG_ERROR(command_logger, COMMAND_SOCKET_READ_FAIL) .arg(ec.value()).arg(socket_->getNative()); } - /// @todo: Should we close the connection, similar to what is already - /// being done for bytes_transferred == 0. + connection_pool_.stop(shared_from_this()); return; } 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) .arg(bytes_transferred).arg(socket_->getNative()); - ConstElementPtr cmd, rsp; + ConstElementPtr rsp; 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_.poll(); + // If we haven't yet received the full command, continue receiving. if (feed_.needData()) { doReceive(); return; } + // Received entire command. Parse the command into JSON. if (feed_.feedOk()) { - cmd = feed_.toElement(); + ConstElementPtr cmd = feed_.toElement(); response_in_progress_ = true; // If successful, then process it as a command. @@ -224,6 +238,9 @@ Connection::receiveHandler(const boost::system::error_code& ec, response_in_progress_ = false; } 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()); } @@ -246,46 +263,39 @@ Connection::receiveHandler(const boost::system::error_code& ec, doSend(); 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()); } void Connection::sendHandler(const boost::system::error_code& ec, size_t bytes_transferred) { - if (ec && ec.value() != boost::asio::error::operation_aborted) { - LOG_ERROR(command_logger, COMMAND_SOCKET_WRITE_FAIL) - .arg(socket_->getNative()).arg(ec.message()); + if (ec) { + // If an error occurred, log this error and stop the connection. + if (ec.value() != boost::asio::error::operation_aborted) { + LOG_ERROR(command_logger, COMMAND_SOCKET_WRITE_FAIL) + .arg(socket_->getNative()).arg(ec.message()); + } } 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); + // Check if there is any data left to be sent and sent it. if (!response_.empty()) { doSend(); return; + } } + // All data sent or an error has occurred. Close the connection. connection_pool_.stop(shared_from_this()); } @@ -392,6 +402,10 @@ CommandMgrImpl::doAccept() { // New connection is arriving. Start asynchronous transmission. ConnectionPtr connection(new Connection(socket_, connection_pool_)); 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. diff --git a/src/lib/config/config_messages.mes b/src/lib/config/config_messages.mes index 40370f7a63..49aeb942a8 100644 --- a/src/lib/config/config_messages.mes +++ b/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, 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 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 This debug message indicates that specified number of bytes was received 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 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 This debug message indicates that the specified number of bytes was sent over command socket identifier by the specified file descriptor. -- 2.47.2