From 1e9f64ef1464a39f780e5f61e0ef28b6dc530e99 Mon Sep 17 00:00:00 2001 From: Ben Deane Date: Mon, 18 Aug 2025 14:31:22 -0600 Subject: [PATCH] :art: Logging: allow writer in env, remove `log_by_{args,buf}` Problem: - The writer has to be supplied in the log config; there are use cases for changing the writer in the environment. For instance this would provide an alternative, more flexible way to do secure logging. - The hardcoded dichotomy between `log_by_args` and `log_by_buf` is annoying and a relic of the original implementation. Solution: - Allow the log writer to be passed in the log environment. - Instead of `log_by_args` and `log_by_buf`, a writer should provide a function that takes the span to write. Now the callee can choose whether to make that a function template and potentially unroll the write loop, or just a function taking a dynamic span with a runtime loop. --- CMakeLists.txt | 2 +- include/log/catalog/encoder.hpp | 46 +++---- include/log/catalog/mipi_builder.hpp | 24 ++-- include/log/catalog/writer.hpp | 24 ++++ test/log/catalog1_lib.cpp | 26 ++-- test/log/catalog2a_lib.cpp | 8 +- test/log/catalog2b_lib.cpp | 14 ++- test/log/encoder.cpp | 180 +++++++++++++-------------- test/log/level.cpp | 11 +- test/log/mipi_logger.cpp | 10 +- 10 files changed, 179 insertions(+), 166 deletions(-) create mode 100644 include/log/catalog/writer.hpp diff --git a/CMakeLists.txt b/CMakeLists.txt index 7087a870..d857c98e 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -25,7 +25,7 @@ include(cmake/string_catalog.cmake) add_versioned_package("gh:boostorg/mp11#boost-1.83.0") fmt_recipe(11.1.3) add_versioned_package("gh:intel/cpp-baremetal-concurrency#09c043b") -add_versioned_package("gh:intel/cpp-std-extensions#8e2f948") +add_versioned_package("gh:intel/cpp-std-extensions#ca9e67a") add_versioned_package("gh:intel/cpp-baremetal-senders-and-receivers#27db6e1") set(GEN_STR_CATALOG diff --git a/include/log/catalog/encoder.hpp b/include/log/catalog/encoder.hpp index 872ddabf..49e09d20 100644 --- a/include/log/catalog/encoder.hpp +++ b/include/log/catalog/encoder.hpp @@ -3,6 +3,7 @@ #include #include #include +#include #include #include #include @@ -44,40 +45,23 @@ template struct to_message_t { template using fn = decltype(to_message()); }; + } // namespace detail template struct log_writer { - template - auto operator()(stdx::span msg) -> void { + auto operator()(auto msg) -> void { stdx::for_each( [&](Dest &dest) { - conc::call_in_critical_section( - [&] { dest.log_by_buf(msg); }); + conc::call_in_critical_section([&] { dest(msg); }); }, dests); } - template - auto operator()(stdx::span msg) -> void { - [&](std::index_sequence) { - stdx::for_each( - [&](Dest &dest) { - conc::call_in_critical_section( - [&] { dest.log_by_args(msg[Is]...); }); - }, - dests); - }(std::make_index_sequence{}); - } - - auto operator()(auto const &msg) -> void { - this->operator()(msg.as_const_view().data()); - } - Destinations dests; }; template log_writer(T) -> log_writer; -template struct log_handler { +template struct log_handler { template auto log(FilenameStringType, LineNumberType, FmtResult const &fr) -> void { @@ -86,8 +70,9 @@ template struct log_handler { template auto log_msg(FmtResult const &fr) -> void { + auto builder = get_builder(Env{}); + writer_like auto writer = stdx::query(get_writer, w); fr.args.apply([&](Args &&...args) { - auto builder = get_builder(Env{}); constexpr auto L = stdx::to_underlying(get_level(Env{})); using Message = typename decltype(builder)::template convert_args< detail::to_message_t struct log_handler { using Module = decltype(detail::to_module()); - w(builder.template build(catalog(), module(), - std::forward(args)...)); + auto const pkt = + builder.template build(catalog(), module(), + std::forward(args)...); + writer(pkt.as_const_view().data()); }); } template auto log_version() -> void { auto builder = get_builder(Env{}); - w(builder.template build_version()); + writer_like auto writer = stdx::query(get_writer, w); + auto const pkt = builder.template build_version(); + writer(pkt.as_const_view().data()); } Writer w; }; -template struct config { - using destinations_tuple_t = stdx::tuple; - constexpr explicit config(TDestinations... dests) +template struct config { + using destinations_tuple_t = stdx::tuple; + constexpr explicit config(Dests... dests) : logger{log_writer{stdx::tuple{std::move(dests)...}}} {} log_handler> logger; }; + template config(Ts...) -> config; } // namespace logging::binary diff --git a/include/log/catalog/mipi_builder.hpp b/include/log/catalog/mipi_builder.hpp index 2829b8a3..f9971130 100644 --- a/include/log/catalog/mipi_builder.hpp +++ b/include/log/catalog/mipi_builder.hpp @@ -69,23 +69,13 @@ template struct builder { using namespace msg; constexpr auto payload_size = (sizeof(id) + ... + sizeof(typename P::template pack_as_t)); - if constexpr (payload_size <= sizeof(uint32_t) * 3) { - constexpr auto header_size = - defn::catalog_msg_t::size::value; - using storage_t = - std::array()>; - return catalog_builder{}.template build( - id, m, args...); - } else { - constexpr auto header_size = - defn::catalog_msg_t::size::value; - using storage_t = - std::array; - return catalog_builder{}.template build( - id, m, args...); - } + constexpr auto header_size = + defn::catalog_msg_t::size::value; + using storage_t = + std::array()>; + return catalog_builder{}.template build(id, m, + args...); } }; diff --git a/include/log/catalog/writer.hpp b/include/log/catalog/writer.hpp new file mode 100644 index 00000000..d3139b81 --- /dev/null +++ b/include/log/catalog/writer.hpp @@ -0,0 +1,24 @@ +#pragma once + +#include + +#include +#include + +#include +#include + +namespace logging::binary { +template +concept writer_like = + requires(T &t, stdx::span data) { t(data); }; + +[[maybe_unused]] constexpr inline struct get_writer_t { + template + CONSTEVAL auto operator()(T &&t) const noexcept( + noexcept(std::forward(t).query(std::declval()))) + -> decltype(std::forward(t).query(*this)) { + return std::forward(t).query(*this); + } +} get_writer; +} // namespace logging::binary diff --git a/test/log/catalog1_lib.cpp b/test/log/catalog1_lib.cpp index 6ace3933..6a846a7a 100644 --- a/test/log/catalog1_lib.cpp +++ b/test/log/catalog1_lib.cpp @@ -4,6 +4,7 @@ #include #include +#include #include @@ -15,10 +16,11 @@ int log_calls{}; std::uint32_t last_header{}; namespace { -struct test_log_args_destination { - auto log_by_args(std::uint32_t hdr, auto...) -> void { +struct test_log_destination { + template + auto operator()(stdx::span pkt) const { ++log_calls; - last_header = hdr; + last_header = pkt[0]; } }; @@ -36,32 +38,32 @@ auto log_with_fixed_string_id() -> void; auto log_with_fixed_module_id() -> void; auto log_zero_args() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"A string with no placeholders">()); } auto log_one_ct_arg() -> void { using namespace stdx::literals; - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"B string with {} placeholder">("one"_ctst)); } auto log_one_32bit_rt_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"C1 string with {} placeholder">(std::int32_t{1})); } auto log_one_64bit_rt_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"C2 string with {} placeholder">(std::int64_t{1})); } auto log_one_formatted_rt_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"C3 string with {:08x} placeholder">(std::int32_t{1})); } @@ -69,7 +71,7 @@ auto log_one_formatted_rt_arg() -> void { auto log_with_non_default_module() -> void { CIB_WITH_LOG_ENV(logging::get_level, logging::level::TRACE, logging::get_module, "not default") { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"ModuleID string with {} placeholder">(1)); } @@ -78,7 +80,7 @@ auto log_with_non_default_module() -> void { auto log_with_fixed_module() -> void { CIB_WITH_LOG_ENV(logging::get_level, logging::level::TRACE, logging::get_module, "fixed") { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"Fixed ModuleID string with {} placeholder">(1)); } @@ -87,7 +89,7 @@ auto log_with_fixed_module() -> void { auto log_with_fixed_string_id() -> void { CIB_WITH_LOG_ENV(logging::get_level, logging::level::TRACE, logging::get_string_id, 1337) { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"Fixed StringID string">()); } @@ -97,7 +99,7 @@ auto log_with_fixed_module_id() -> void { CIB_WITH_LOG_ENV(logging::get_level, logging::level::TRACE, logging::get_module_id, 7, logging::get_module, "fixed_id") { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"Fixed ModuleID string with {} placeholder">(1)); } diff --git a/test/log/catalog2a_lib.cpp b/test/log/catalog2a_lib.cpp index 3d7d9322..b71e703e 100644 --- a/test/log/catalog2a_lib.cpp +++ b/test/log/catalog2a_lib.cpp @@ -4,6 +4,7 @@ #include #include +#include #include @@ -14,10 +15,9 @@ template <> inline auto conc::injected_policy<> = test_conc_policy{}; extern int log_calls; namespace { -struct test_log_args_destination { - auto log_by_args(std::uint32_t, auto...) -> void { ++log_calls; } +struct test_log_destination { template - auto log_by_buf(stdx::span) const { + auto operator()(stdx::span) const { ++log_calls; } }; @@ -28,7 +28,7 @@ using log_env2a = stdx::make_env_t; auto log_two_rt_args() -> void; auto log_two_rt_args() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; cfg.logger.log_msg( stdx::ct_format<"D string with {} and {} placeholder">( std::uint32_t{1}, std::int64_t{2})); diff --git a/test/log/catalog2b_lib.cpp b/test/log/catalog2b_lib.cpp index 858807ca..9f9de82c 100644 --- a/test/log/catalog2b_lib.cpp +++ b/test/log/catalog2b_lib.cpp @@ -4,6 +4,7 @@ #include #include +#include #include @@ -14,8 +15,11 @@ template <> inline auto conc::injected_policy<> = test_conc_policy{}; extern int log_calls; namespace { -struct test_log_args_destination { - auto log_by_args(std::uint32_t, auto...) -> void { ++log_calls; } +struct test_log_destination { + template + auto operator()(stdx::span) const { + ++log_calls; + } }; using log_env2b = stdx::make_env_t; @@ -26,21 +30,21 @@ auto log_rt_float_arg() -> void; auto log_rt_double_arg() -> void; auto log_rt_enum_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; using namespace ns; cfg.logger.log_msg( stdx::ct_format<"E string with {} placeholder">(E::value)); } auto log_rt_float_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; using namespace ns; cfg.logger.log_msg( stdx::ct_format<"Float string with {} placeholder">(3.14f)); } auto log_rt_double_arg() -> void { - auto cfg = logging::binary::config{test_log_args_destination{}}; + auto cfg = logging::binary::config{test_log_destination{}}; using namespace ns; cfg.logger.log_msg( stdx::ct_format<"Double string with {} placeholder">(3.14)); diff --git a/test/log/encoder.cpp b/test/log/encoder.cpp index 8fe58bb0..d2d14465 100644 --- a/test/log/encoder.cpp +++ b/test/log/encoder.cpp @@ -88,60 +88,62 @@ constexpr auto check_buffer = [](auto data) { }; template -struct test_log_args_destination { - template - auto log_by_args(std::uint32_t header, Args... args) { - constexpr auto Header = - expected_msg_header(Level, test_module_id, sizeof...(ExpectedArgs)); - CHECK(header == Header); - (check(args, ExpectedArgs), ...); - ++num_log_args_calls; - } -}; - -template -struct test_log_buf_destination { - auto log_by_buf(stdx::span data) const { - REQUIRE(data.size() == - (sizeof...(ExpectedArgs) + 1) * sizeof(std::uint32_t)); - constexpr auto Header = - expected_msg_header(Level, test_module_id, sizeof...(ExpectedArgs)); - check_buffer(data); +struct test_log_destination { + constexpr static auto Header = + expected_msg_header(Level, test_module_id, sizeof...(ExpectedArgs)); + + template + auto operator()(stdx::span pkt) const { + std::uint32_t const *p = pkt.data(); + REQUIRE(pkt.size() == 1 + sizeof...(ExpectedArgs)); + CHECK(*p++ == Header); + (check(*p++, ExpectedArgs), ...); ++num_log_args_calls; } }; template struct test_log_version_destination { - template - auto log_by_args(std::uint32_t header, Args... args) { - CHECK(header == Header); - (check(args, ExpectedArgs), ...); + template + auto operator()(stdx::span pkt) const { + std::uint32_t const *p = pkt.data(); + REQUIRE(pkt.size() == 1 + sizeof...(ExpectedArgs)); + CHECK(*p++ == Header); + (check(*p++, ExpectedArgs), ...); ++num_log_args_calls; } - auto log_by_buf(stdx::span data) const { - check_buffer(data); + auto operator()(stdx::span pkt) const { + check_buffer(pkt); ++num_log_args_calls; } }; -template struct test_log_float_args_destination { - auto log_by_args(std::uint32_t header, auto, auto arg) { - constexpr auto Header = expected_msg_header(Level, test_module_id, 1); - CHECK(header == Header); - CHECK(stdx::bit_cast(arg) == expected); +template struct test_log_float_destination { + constexpr static auto Header = + expected_msg_header(Level, test_module_id, 1); + + template + auto operator()(stdx::span pkt) const { + std::uint32_t const *p = pkt.data(); + REQUIRE(pkt.size() == 3); + CHECK(*p++ == Header); + CHECK(stdx::bit_cast(p[1]) == expected); ++num_log_args_calls; } float expected{}; }; -template struct test_log_double_args_destination { - auto log_by_args(std::uint32_t header, auto, std::uint32_t lo, - std::uint32_t hi) { - constexpr auto Header = expected_msg_header(Level, test_module_id, 1); - CHECK(header == Header); - std::array arr{lo, hi}; +template struct test_log_double_destination { + constexpr static auto Header = + expected_msg_header(Level, test_module_id, 1); + + template + auto operator()(stdx::span pkt) const { + std::uint32_t const *p = pkt.data(); + REQUIRE(pkt.size() == 4); + CHECK(*p++ == Header); + std::array arr{p[1], p[2]}; CHECK(stdx::bit_cast(arr) == expected); ++num_log_args_calls; } @@ -185,8 +187,8 @@ TEST_CASE("argument encoding", "[mipi]") { TEST_CASE("log zero arguments", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; - auto cfg = logging::binary::config{ - test_log_args_destination{}}; + auto cfg = + logging::binary::config{test_log_destination{}}; cfg.logger.log_msg(stdx::ct_format<"Hello">()); CHECK(test_critical_section::count == 2); } @@ -195,7 +197,7 @@ TEST_CASE("log one integral 32-bit argument", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; auto cfg = logging::binary::config{ - test_log_args_destination{}}; + test_log_destination{}}; cfg.logger.log_msg(stdx::ct_format<"{}">(17u)); CHECK(test_critical_section::count == 2); } @@ -204,7 +206,7 @@ TEST_CASE("log one floating-point 32-bit argument", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; auto cfg = logging::binary::config{ - test_log_float_args_destination{3.14f}}; + test_log_float_destination{3.14f}}; cfg.logger.log_msg(stdx::ct_format<"{}">(3.14f)); CHECK(test_critical_section::count == 2); } @@ -214,8 +216,8 @@ TEST_CASE("log one 64-bit argument", "[mipi]") { test_critical_section::count = 0; auto x = std::uint64_t{0x1234'5678'90ab'cdefull}; auto cfg = logging::binary::config{ - test_log_args_destination{}}; + test_log_destination{}}; cfg.logger.log_msg(stdx::ct_format<"{}">(x)); CHECK(test_critical_section::count == 2); } @@ -224,7 +226,7 @@ TEST_CASE("log one floating-point 64-bit argument", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; auto cfg = logging::binary::config{ - test_log_double_args_destination{3.14}}; + test_log_double_destination{3.14}}; cfg.logger.log_msg(stdx::ct_format<"{}">(3.14)); CHECK(test_critical_section::count == 2); } @@ -233,50 +235,18 @@ TEST_CASE("log two arguments", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; auto cfg = logging::binary::config{ - test_log_args_destination{}}; + test_log_destination{}}; cfg.logger.log_msg(stdx::ct_format<"{} {}">(17u, 18u)); CHECK(test_critical_section::count == 2); } -TEST_CASE("log more than two arguments", "[mipi]") { - CIB_LOG_ENV(logging::get_level, logging::level::TRACE); - { - test_critical_section::count = 0; - auto cfg = logging::binary::config{ - test_log_buf_destination{}}; - cfg.logger.log_msg(stdx::ct_format<"{} {} {}">(17u, 18u, 19u)); - CHECK(test_critical_section::count == 2); - } - { - test_critical_section::count = 0; - auto cfg = logging::binary::config{ - test_log_buf_destination{}}; - cfg.logger.log_msg( - stdx::ct_format<"{} {} {} {}">(17u, 18u, 'a', 'b')); - CHECK(test_critical_section::count == 2); - } -} - -TEST_CASE("log more than two arguments whose size fits in two uint32_ts", - "[mipi]") { - CIB_LOG_ENV(logging::get_level, logging::level::TRACE); - test_critical_section::count = 0; - auto cfg = logging::binary::config{ - test_log_buf_destination{}}; - cfg.logger.log_msg(stdx::ct_format<"{} {} {}">('a', 'b', 'c')); - CHECK(test_critical_section::count == 2); -} - TEST_CASE("log to multiple destinations", "[mipi]") { CIB_LOG_ENV(logging::get_level, logging::level::TRACE); test_critical_section::count = 0; num_log_args_calls = 0; auto cfg = logging::binary::config{ - test_log_args_destination{}, - test_log_args_destination{}}; + test_log_destination{}, + test_log_destination{}}; cfg.logger.log_msg(stdx::ct_format<"{} {}">(17u, 18u)); CHECK(test_critical_section::count == 4); @@ -325,16 +295,18 @@ namespace { std::vector expected_args{}; template struct test_log_injected_destination { - template - auto log_by_args(std::uint32_t header, Args... args) { + + template + auto operator()(stdx::span pkt) const { ++num_log_args_calls; auto const Header = expected_msg_header(Level, test_module_id, std::size(expected_args)); - REQUIRE(header == Header); - REQUIRE(sizeof...(Args) == std::size(expected_args)); - [&](std::index_sequence) { - (check(args, expected_args[Is]), ...); - }(std::make_index_sequence{}); + + std::uint32_t const *p = pkt.data(); + CHECK(*p++ == Header); + for (auto &e : expected_args) { + check(*p++, e); + } } }; } // namespace @@ -384,13 +356,14 @@ namespace { int num_catalog_args_calls{}; template struct test_catalog_args_destination { - template - auto log_by_args(std::uint32_t header, std::uint32_t id, Args...) { - constexpr auto Header = - expected_catalog32_header(Level, test_module_id); - CHECK(header == Header); - CHECK(id == test_string_id); - STATIC_REQUIRE(sizeof...(Args) == 0); + constexpr static auto Header = + expected_catalog32_header(Level, test_module_id); + + template + auto operator()(stdx::span pkt) const { + REQUIRE(pkt.size() == 2); + CHECK(pkt[0] == Header); + CHECK(pkt[1] == test_string_id); ++num_catalog_args_calls; } }; @@ -417,3 +390,26 @@ TEST_CASE("log with overridden builder", "[mipi]") { cfg.logger.log_msg(stdx::ct_format<"Hello">()); CHECK(num_catalog_args_calls == 1); } + +namespace { +int num_custom_writer_calls{}; + +struct custom_writer { + auto operator()(stdx::span) const -> void { + ++num_custom_writer_calls; + } +}; +} // namespace + +TEST_CASE("log with overridden writer", "[mipi]") { + using catalog_env = + stdx::make_env_t; + + num_custom_writer_calls = 0; + auto cfg = + logging::binary::config{test_log_destination{}}; + + cfg.logger.log_msg(stdx::ct_format<"Hello">()); + CHECK(num_custom_writer_calls == 1); +} diff --git a/test/log/level.cpp b/test/log/level.cpp index 0d0b54b3..af9df843 100644 --- a/test/log/level.cpp +++ b/test/log/level.cpp @@ -5,6 +5,7 @@ #include #include #include +#include #include @@ -47,9 +48,13 @@ namespace { int log_calls{}; struct test_destination { - auto log_by_args(std::uint32_t header, auto id, auto &&...) { - CHECK(header == 0x01'5a'00'53); - CHECK(id == 0xdeadbeef); + template + auto operator()(stdx::span pkt) const { + using namespace msg; + auto const msg = + msg::const_view{pkt}; + CHECK(msg.get("severity"_f) == + stdx::to_underlying(custom_level::THE_ONE_LEVEL)); ++log_calls; } }; diff --git a/test/log/mipi_logger.cpp b/test/log/mipi_logger.cpp index 4fde4469..23d4d6a3 100644 --- a/test/log/mipi_logger.cpp +++ b/test/log/mipi_logger.cpp @@ -1,6 +1,7 @@ #include #include +#include #include @@ -17,10 +18,11 @@ template <> inline auto version::config<> = version_config{}; namespace { template struct test_log_version_destination { - template - auto log_by_args(std::uint32_t header, Args... args) { - CHECK(header == Header); - (check(args, ExpectedArgs), ...); + template + auto operator()(stdx::span pkt) const { + std::uint32_t const *p = pkt.data(); + CHECK(*p++ == Header); + (check(*p++, ExpectedArgs), ...); } }; } // namespace