From 7292ca453a769385b09fca5973d696b62010ad24 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Korina=20=C5=A0imi=C4=8Devi=C4=87?= Date: Wed, 19 Feb 2025 13:06:11 +0100 Subject: [PATCH] Add tests to verify correct logging output based on log level Summary: related to T15252 - Add logger tests that verify correct logging output based on log_level & cover all functions and branches - Changed default log_level to info Reviewers: ivica Reviewed By: ivica Subscribers: iljazovic, miljen Differential Revision: https://repo.mireo.local/D33830 --- .github/workflows/coverage.yml | 3 +- include/boost/mqtt5/logger.hpp | 12 +- test/src/run_tests.cpp | 4 +- test/unit/logger.cpp | 384 ++++++++++++++++++++++++++++++++- 4 files changed, 385 insertions(+), 18 deletions(-) diff --git a/.github/workflows/coverage.yml b/.github/workflows/coverage.yml index db1f1c0..985fe94 100644 --- a/.github/workflows/coverage.yml +++ b/.github/workflows/coverage.yml @@ -33,7 +33,7 @@ jobs: container: ${{ matrix.container }} env: CXXFLAGS: ${{ matrix.cxxflags }} - LDFLAGS: ${{ matrix.ldflags }} + LDFLAGS: ${{ matrix.ldflags }} CMAKE_BUILD_PARALLEL_LEVEL: 4 steps: @@ -82,3 +82,4 @@ jobs: disable_search: true fail_ci_if_error: true plugins: noop + token: ${{ secrets.CODECOV_TOKEN }} diff --git a/include/boost/mqtt5/logger.hpp b/include/boost/mqtt5/logger.hpp index 8dc32bb..f430582 100644 --- a/include/boost/mqtt5/logger.hpp +++ b/include/boost/mqtt5/logger.hpp @@ -69,7 +69,7 @@ public: * * \param level Messages with a log level higher than the given log level will be suppressed. */ - logger(log_level level = log_level::warning) : _level(level) {} + logger(log_level level = log_level::info) : _level(level) {} /** * \brief Outputs the results of the resolve operation. @@ -90,7 +90,7 @@ public: std::clog << "resolve: " << host << ":" << port; - std::clog << " - " << ec.message(); + std::clog << " - " << ec.message() << "."; if (_level == log_level::debug) { std::clog << " ["; @@ -118,7 +118,7 @@ public: std::clog << "TCP connect: " << ep.address().to_string() << ":" << ep.port() - << " - " << ec.message() + << " - " << ec.message() << "." << std::endl; } @@ -136,7 +136,7 @@ public: std::clog << "TLS handshake: " << ep.address().to_string() << ":" << ep.port() - << " - " << ec.message() + << " - " << ec.message() << "." << std::endl; } @@ -154,7 +154,7 @@ public: std::clog << "WebSocket handshake: " << ep.address().to_string() << ":" << ep.port() - << " - " << ec.message() + << " - " << ec.message() << "." << std::endl; } @@ -230,7 +230,7 @@ private: if (i + 1 < val.size()) std::clog << ", "; } - std::clog << "]"; + std::clog << "] "; } return true; } diff --git a/test/src/run_tests.cpp b/test/src/run_tests.cpp index 79d7b33..3d00b73 100644 --- a/test/src/run_tests.cpp +++ b/test/src/run_tests.cpp @@ -5,7 +5,7 @@ // (See accompanying file LICENSE or copy at http://www.boost.org/LICENSE_1_0.txt) // -#define BOOST_TEST_MODULE boost::mqtt5_tests +#define BOOST_TEST_MODULE boost_mqtt5_tests #include @@ -24,5 +24,5 @@ int main(int argc, char* argv[]) { * example: ./mqtt-test --log_level=test_suite * * all boost test parameters can be found here: -* https://www.boost.org/doc/libs/1_82_0/libs/test/doc/html/boost_test/runtime_config/summary.html +* https://www.boost.org/doc/libs/master/libs/test/doc/html/boost_test/runtime_config/summary.html */ diff --git a/test/unit/logger.cpp b/test/unit/logger.cpp index b38a5b3..3376529 100644 --- a/test/unit/logger.cpp +++ b/test/unit/logger.cpp @@ -14,11 +14,13 @@ #include #include #include +#include #include #include #include #include +#include #include #include @@ -42,13 +44,13 @@ void logger_test() { BOOST_AUTO_TEST_SUITE(logger_tests) +using error_code = boost::system::error_code; + class clog_redirect { std::streambuf* _old_buffer; public: - clog_redirect( - std::streambuf* new_buffer - ) : + clog_redirect(std::streambuf* new_buffer) : _old_buffer(std::clog.rdbuf(new_buffer)) {} @@ -62,10 +64,375 @@ bool contains(const std::string& str, const std::string& substr) { return str.find(substr) != std::string::npos; } -BOOST_AUTO_TEST_CASE(disconnect) { +// Error code messages differ from platform to platform. + +std::string success_msg() { + error_code ec; + return ec.message(); +} + +std::string host_not_found_msg() { + error_code ec = asio::error::host_not_found; + return ec.message(); +} + +std::string not_connected_msg() { + error_code ec = asio::error::not_connected; + return ec.message(); +} + +// Test logger output based on log level. + +template +void test_logger_output(TestFun&& fun, const std::string& expected_output) { + boost::test_tools::output_test_stream output; + { + clog_redirect guard(output.rdbuf()); + fun(); + } + + auto realized_output = output.rdbuf()->str(); + BOOST_TEST(realized_output == expected_output); +} + +// at_resolve + +struct resolve_test_data { + std::string_view host = "localhost"; + std::string_view port = "1883"; + + asio::ip::tcp::resolver::results_type endpoints() { + auto ex = asio::system_executor {}; + asio::ip::tcp::resolver resolver(ex); + error_code ec; + auto eps = resolver.resolve(host, port, ec); + BOOST_TEST_REQUIRE(!ec); + return eps; + } + + std::string endpoints_output() { + // Endpoints resolved depend on the platform. + auto eps = endpoints(); + std::stringstream ss; + ss << "["; + for (auto it = eps.begin(); it != eps.end();) { + ss << it->endpoint().address().to_string(); + if (++it != eps.end()) + ss << ","; + } + ss << "]"; + return ss.str(); + } +}; + +BOOST_FIXTURE_TEST_CASE(at_resolve_success_warning, resolve_test_data) { + const auto expected_output = ""; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_resolve(error_code {}, host, port, endpoints()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_resolve_fail_warning, resolve_test_data) { + const auto expected_output = + "[Boost.MQTT5] resolve: localhost:1883 - " + host_not_found_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_resolve(asio::error::host_not_found, host, port, {}); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_resolve_info, resolve_test_data) { + const auto expected_output = + "[Boost.MQTT5] resolve: localhost:1883 - " + success_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_resolve(error_code {}, host, port, endpoints()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_resolve_success_debug, resolve_test_data) { + const auto expected_output = + "[Boost.MQTT5] resolve: localhost:1883 - " + success_msg() + ". " + endpoints_output() + "\n" + ; + + auto test_fun = [this] { + logger l(log_level::debug); + l.at_resolve(error_code {}, host, port, endpoints()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_resolve_fail_debug, resolve_test_data) { + const auto expected_output = + "[Boost.MQTT5] resolve: localhost:1883 - " + host_not_found_msg() + ". []\n" + ; + + auto test_fun = [this] { + logger l(log_level::debug); + l.at_resolve(asio::error::host_not_found, host, port, {}); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +struct tcp_endpoint { + const asio::ip::tcp::endpoint ep = { asio::ip::make_address_v4("127.0.0.1"), 1883 }; + + std::string endpoint_output() { + return ep.address().to_string() + ":" + std::to_string(ep.port()); + } +}; + +// at_tcp_connect + +BOOST_FIXTURE_TEST_CASE(at_tcp_connect_success_warning, tcp_endpoint) { + const auto expected_output = ""; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_tcp_connect(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_tcp_connect_fail_warning, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] TCP connect: " + endpoint_output() + " - " + not_connected_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_tcp_connect(asio::error::not_connected, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_tcp_connect_info, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] TCP connect: " + endpoint_output() + " - " + success_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_tcp_connect(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +// at_tls_handshake + +BOOST_FIXTURE_TEST_CASE(at_tls_handshake_success_warning, tcp_endpoint) { + const auto expected_output = ""; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_tls_handshake(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_tls_handshake_fail_warning, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] TLS handshake: " + endpoint_output() + " - " + not_connected_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_tls_handshake(asio::error::not_connected, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_tls_handshake_info, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] TLS handshake: " + endpoint_output() + " - " + success_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_tls_handshake(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +// at_ws_handshake + +BOOST_FIXTURE_TEST_CASE(at_ws_handshake_success_warning, tcp_endpoint) { + const auto expected_output = ""; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_ws_handshake(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_ws_handshake_fail_warning, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] WebSocket handshake: " + endpoint_output() + " - " + not_connected_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_ws_handshake(asio::error::not_connected, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_ws_handshake_info, tcp_endpoint) { + const auto expected_output = + "[Boost.MQTT5] WebSocket handshake: " + endpoint_output() + " - " + success_msg() + ".\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_ws_handshake(error_code {}, ep); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +// at_connack + +struct connack_test_data { + connack_props ca_props() { + connack_props cprops; + cprops[prop::user_property] = { { "key_1", "val_1" }, {"key_2", "val_2"} };; + cprops[prop::subscription_identifier_available] = uint8_t(1); + cprops[prop::assigned_client_identifier] = "client_id"; + return cprops; + } +}; + +BOOST_FIXTURE_TEST_CASE(at_connack_success_warning, connack_test_data) { + const auto expected_output = ""; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_connack(reason_codes::success, false, ca_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_connack_fail_warning, connack_test_data) { + const auto expected_output = + "[Boost.MQTT5] connack: The Client ID is valid but not allowed by this Server.\n" + ; + + auto test_fun = [this] { + logger l(log_level::warning); + l.at_connack(reason_codes::client_identifier_not_valid, false, ca_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_connack_info, connack_test_data) { + const auto expected_output = + "[Boost.MQTT5] connack: The operation completed successfully.\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_connack(reason_codes::success, false, ca_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_connack_debug, connack_test_data) { + const auto expected_output = + "[Boost.MQTT5] connack: The operation completed successfully. " + "session_present:0 " + "assigned_client_identifier:client_id " + "user_property:[(key_1,val_1), (key_2,val_2)] " + "subscription_identifier_available:1 \n" + ; + + auto test_fun = [this] { + logger l(log_level::debug); + l.at_connack(reason_codes::success, false, ca_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +// at_disconnect + +struct disconnect_test_data { + disconnect_props dc_props() { + disconnect_props dprops; + dprops[prop::reason_string] = "No reason."; + return dprops; + } +}; + +BOOST_FIXTURE_TEST_CASE(at_disconnect_info, disconnect_test_data) { + const auto expected_output = + "[Boost.MQTT5] disconnect: Close the connection normally. " + "Do not send the Will Message.\n" + ; + + auto test_fun = [this] { + logger l(log_level::info); + l.at_disconnect(reason_codes::normal_disconnection, dc_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +BOOST_FIXTURE_TEST_CASE(at_disconnect_debug, disconnect_test_data) { + const auto expected_output = + "[Boost.MQTT5] disconnect: Close the connection normally. " + "Do not send the Will Message.reason_string:No reason. \n" + ; + + auto test_fun = [this] { + logger l(log_level::debug); + l.at_disconnect(reason_codes::normal_disconnection, dc_props()); + }; + + test_logger_output(std::move(test_fun), expected_output); +} + +// Test that the mqtt_client calls logger functions as expected. + +BOOST_AUTO_TEST_CASE(client_disconnect) { using test::after; using namespace std::chrono_literals; + const auto& success = success_msg(); + const auto expected_msg = + "[Boost.MQTT5] resolve: 127.0.0.1:1883 - " + success + ".\n" + "[Boost.MQTT5] TCP connect: 127.0.0.1:1883 - " + success + ".\n" + "[Boost.MQTT5] connack: The operation completed successfully.\n" + "[Boost.MQTT5] disconnect: Close the connection normally. Do not send the Will Message.\n" + "[Boost.MQTT5] resolve: 127.0.0.1:1883 - " + success + ".\n" + "[Boost.MQTT5] TCP connect: 127.0.0.1:1883 - " + success + ".\n" + ; + boost::test_tools::output_test_stream output; { clog_redirect guard(output.rdbuf()); @@ -83,7 +450,7 @@ BOOST_AUTO_TEST_CASE(disconnect) { test::msg_exchange broker_side; broker_side .expect(connect) - .complete_with(error_code{}, after(0ms)) + .complete_with(error_code {}, after(0ms)) .reply_with(connack, after(0ms)) .send(disconnect, after(50ms)) .expect(connect); @@ -107,8 +474,7 @@ BOOST_AUTO_TEST_CASE(disconnect) { } std::string log = output.rdbuf()->str(); - BOOST_TEST_MESSAGE(log); - BOOST_TEST(contains(log, "disconnect")); + BOOST_TEST(log == expected_msg); } #ifdef BOOST_MQTT5_EXTRA_DEPS @@ -119,7 +485,7 @@ using context_type = asio::ssl::context; using logger_type = logger; using client_type = mqtt_client; -BOOST_AUTO_TEST_CASE(successful_connect_debug, +BOOST_AUTO_TEST_CASE(client_successful_connect_debug, * boost::unit_test::precondition(test::public_broker_cond)) { boost::test_tools::output_test_stream output; @@ -150,7 +516,7 @@ BOOST_AUTO_TEST_CASE(successful_connect_debug, BOOST_TEST_WARN(contains(log, "connack")); } -BOOST_AUTO_TEST_CASE(successful_connect_warning, +BOOST_AUTO_TEST_CASE(client_successful_connect_warning, * boost::unit_test::precondition(test::public_broker_cond)) { boost::test_tools::output_test_stream output;