From: Thomas Markwalder Date: Tue, 5 Jun 2018 15:06:15 +0000 (-0400) Subject: [5599] Control channel now emits info on any discarded data X-Git-Tag: trac5694_base~2^2~5^2 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=e47da044a9ad1dad7e848a7bc05854a0b65f1555;p=thirdparty%2Fkea.git [5599] Control channel now emits info on any discarded data doc/guide/ctrl-channel.xml Minor update to using socat src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc Updated testing for server response to server side control channel timeouts src/lib/cc/json_feed.h JSONFeed::getProcessedText() - new method that returns a copy of the current accumulation of accepted text src/lib/config/config_messages.mes src/lib/config/command_mgr.cc Connection::receiveHandler() - added log info about discarded data when client closes connection Connection::timeoutHandler() - added info about discarded data to server's response to client on server side timeout --- diff --git a/doc/guide/ctrl-channel.xml b/doc/guide/ctrl-channel.xml index 02c593fb5d..ea2c9bd267 100644 --- a/doc/guide/ctrl-channel.xml +++ b/doc/guide/ctrl-channel.xml @@ -227,9 +227,14 @@ such as socat and curl. In order to control the given Kea service via unix domain socket, use - socat as follows: + socat in interactive mode as follows: $ socat UNIX:/path/to/the/kea/socket - + + or in batch mode, include the "ignoreeof" option as shown below to ensure + socat waits long enough for the server to respond: + +$ echo "{ some command...}" | socat UNIX:/path/to/the/kea/socket -,ignoreeof where /path/to/the/kea/socket is the path specified in the Dhcp4/control-socket/socket-name parameter in the Kea diff --git a/src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc b/src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc index e5fe3f1dfe..60f41f8768 100644 --- a/src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc +++ b/src/bin/dhcp4/tests/ctrl_dhcp4_srv_unittest.cc @@ -1414,8 +1414,8 @@ TEST_F(CtrlChannelDhcpv4SrvTest, longResponse) { } // This test verifies that the server signals timeout if the transmission -// takes too long. -TEST_F(CtrlChannelDhcpv4SrvTest, connectionTimeout) { +// takes too long, after receiving a partial command. +TEST_F(CtrlChannelDhcpv4SrvTest, connectionTimeoutPartialCommand) { createUnixChannelServer(); // Set connection timeout to 2s to prevent long waiting time for the @@ -1462,11 +1462,57 @@ TEST_F(CtrlChannelDhcpv4SrvTest, connectionTimeout) { th.join(); // Check that the server has signalled a timeout. - EXPECT_EQ("{ \"result\": 1, \"text\": \"Connection over control channel" - " timed out\" }", response); + EXPECT_EQ("{ \"result\": 1, \"text\": " + "\"Connection over control channel timed out, " + "discarded partial command of 19 bytes\" }" , response); } +// This test verifies that the server signals timeout if the transmission +// takes too long, having received no data from the client. +TEST_F(CtrlChannelDhcpv4SrvTest, connectionTimeoutNoData) { + createUnixChannelServer(); + + // Set connection timeout to 2s to prevent long waiting time for the + // timeout during this test. + const unsigned short timeout = 2; + CommandMgr::instance().setConnectionTimeout(timeout); + + // Server's response will be assigned to this variable. + std::string response; + + // It is useful to create a thread and run the server and the client + // at the same time and independently. + std::thread th([this, &response]() { + // IO service will be stopped automatically when this object goes + // out of scope and is destroyed. This is useful because we use + // asserts which may break the thread in various exit points. + IOServiceWork work(getIOService()); + // Create the client and connect it to the server. + boost::scoped_ptr client(new UnixControlClient()); + ASSERT_TRUE(client); + ASSERT_TRUE(client->connectToServer(socket_path_)); + + // Let's wait up to 15s for the server's response. The response + // should arrive sooner assuming that the timeout mechanism for + // the server is working properly. + const unsigned int timeout = 15; + ASSERT_TRUE(client->getResponse(response, timeout)); + + // Explicitly close the client's connection. + client->disconnectFromServer(); + }); + + // Run the server until stopped. + getIOService()->run(); + + // Wait for the thread to return. + th.join(); + + // Check that the server has signalled a timeout. + EXPECT_EQ("{ \"result\": 1, \"text\": " + "\"Connection over control channel timed out\" }", response); +} } // End of anonymous namespace diff --git a/src/bin/dhcp6/tests/ctrl_dhcp6_srv_unittest.cc b/src/bin/dhcp6/tests/ctrl_dhcp6_srv_unittest.cc index e6fcb40ab4..c11fb801d3 100644 --- a/src/bin/dhcp6/tests/ctrl_dhcp6_srv_unittest.cc +++ b/src/bin/dhcp6/tests/ctrl_dhcp6_srv_unittest.cc @@ -1435,8 +1435,8 @@ TEST_F(CtrlChannelDhcpv6SrvTest, longResponse) { } // This test verifies that the server signals timeout if the transmission -// takes too long. -TEST_F(CtrlChannelDhcpv6SrvTest, connectionTimeout) { +// takes too long, having received a partial command. +TEST_F(CtrlChannelDhcpv6SrvTest, connectionTimeoutPartialCommand) { createUnixChannelServer(); // Set connection timeout to 2s to prevent long waiting time for the @@ -1483,9 +1483,58 @@ TEST_F(CtrlChannelDhcpv6SrvTest, connectionTimeout) { th.join(); // Check that the server has signalled a timeout. - EXPECT_EQ("{ \"result\": 1, \"text\": \"Connection over control channel" - " timed out\" }", response); + EXPECT_EQ("{ \"result\": 1, \"text\": " + "\"Connection over control channel timed out," + " discarded partial command of 19 bytes\" }", response); } +// This test verifies that the server signals timeout if the transmission +// takes too long, having received no data. +TEST_F(CtrlChannelDhcpv6SrvTest, connectionTimeoutNoData) { + createUnixChannelServer(); + + // Set connection timeout to 2s to prevent long waiting time for the + // timeout during this test. + const unsigned short timeout = 2; + CommandMgr::instance().setConnectionTimeout(timeout); + + // Server's response will be assigned to this variable. + std::string response; + + // It is useful to create a thread and run the server and the client + // at the same time and independently. + std::thread th([this, &response]() { + + // IO service will be stopped automatically when this object goes + // out of scope and is destroyed. This is useful because we use + // asserts which may break the thread in various exit points. + IOServiceWork work(getIOService()); + + // Create the client and connect it to the server. + boost::scoped_ptr client(new UnixControlClient()); + ASSERT_TRUE(client); + ASSERT_TRUE(client->connectToServer(socket_path_)); + + // Having sent nothing let's just wait and see if Server times us out. + // Let's wait up to 15s for the server's response. The response + // should arrive sooner assuming that the timeout mechanism for + // the server is working properly. + const unsigned int timeout = 15; + ASSERT_TRUE(client->getResponse(response, timeout)); + + // Explicitly close the client's connection. + client->disconnectFromServer(); + }); + + // Run the server until stopped. + getIOService()->run(); + + // Wait for the thread to return. + th.join(); + + // Check that the server has signalled a timeout. + EXPECT_EQ("{ \"result\": 1, \"text\": " + "\"Connection over control channel timed out\" }", response); +} } // End of anonymous namespace diff --git a/src/lib/cc/json_feed.h b/src/lib/cc/json_feed.h index 5ebef68f14..ce3d026f18 100644 --- a/src/lib/cc/json_feed.h +++ b/src/lib/cc/json_feed.h @@ -164,6 +164,11 @@ public: return (error_message_); } + /// @brief Returns the text parsed into the buffer. + std::string getProcessedText() const { + return (output_); + } + /// @brief Returns processed data as a structure of @ref isc::data::Element /// objects. /// diff --git a/src/lib/config/command_mgr.cc b/src/lib/config/command_mgr.cc index 5129383461..b9668bc139 100644 --- a/src/lib/config/command_mgr.cc +++ b/src/lib/config/command_mgr.cc @@ -258,11 +258,19 @@ Connection::receiveHandler(const boost::system::error_code& ec, size_t bytes_transferred) { if (ec) { if (ec.value() == boost::asio::error::eof) { + std::stringstream os; + if (feed_.getProcessedText().empty()) { + os << "no input data to discard"; + } + else { + os << "discarding partial command of " + << feed_.getProcessedText().size() << " bytes"; + } + // Foreign host has closed the connection. We should remove it from the // connection pool. LOG_INFO(command_logger, COMMAND_SOCKET_CLOSED_BY_FOREIGN_HOST) - .arg(socket_->getNative()); - + .arg(socket_->getNative()).arg(os.str()); } else if (ec.value() != boost::asio::error::operation_aborted) { LOG_ERROR(command_logger, COMMAND_SOCKET_READ_FAIL) .arg(ec.value()).arg(socket_->getNative()); @@ -384,8 +392,14 @@ Connection::timeoutHandler() { .arg(ex.what()); } - ConstElementPtr rsp = createAnswer(CONTROL_RESULT_ERROR, "Connection over" - " control channel timed out"); + std::stringstream os; + os << "Connection over control channel timed out"; + if (!feed_.getProcessedText().empty()) { + os << ", discarded partial command of " + << feed_.getProcessedText().size() << " bytes"; + } + + ConstElementPtr rsp = createAnswer(CONTROL_RESULT_ERROR, os.str()); response_ = rsp->str(); doSend(); } diff --git a/src/lib/config/config_messages.mes b/src/lib/config/config_messages.mes index 645bba692a..cdec5f8bcc 100644 --- a/src/lib/config/config_messages.mes +++ b/src/lib/config/config_messages.mes @@ -48,9 +48,10 @@ 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_CLOSED_BY_FOREIGN_HOST Closed command socket %1 by foreign host +% COMMAND_SOCKET_CLOSED_BY_FOREIGN_HOST Closed command socket %1 by foreign host, %2 This is an information message indicating that the command connection has been -closed by a command control client. +closed by a command control client, and whether or not any partially read data +was discarded. % COMMAND_SOCKET_CONNECTION_CANCEL_FAIL Failed to cancel read operation on socket %1: %2 This error message is issued to indicate an error to cancel asynchronous read