Logging

How it fits together

A log call in cib is split in two. Library code says what happened through a macro; the application decides where it goes by specializing one variable template. Library headers compile identically whether the program ends up printing text, emitting binary packets, or discarding everything.

Quick start

#include <log/log.hpp>

namespace uart {
CIB_LOG_MODULE("uart");          // every log in this namespace reports module "uart"

inline auto send(std::uint8_t b) -> void {
    CIB_INFO("byte {}", b);
}
} // namespace uart

#include <log_fmt/logger.hpp>
#include <iostream>
#include <iterator>

template <>
inline auto logging::config<> =
    logging::fmt::config{std::ostream_iterator<char>(std::cout)};

target_link_libraries(uart_lib PUBLIC cib_log)       # library: interface only
target_link_libraries(app      PUBLIC cib_log_fmt)   # app: the chosen backend

Macros & levels

The levels are the MIPI Sys-T severities: MAX=0, FATAL=1, ERROR=2, WARN=3, INFO=4, USER1=5, USER2=6, TRACE=7. Nothing in cib filters by level — every call reaches the backend, which decides what to keep.

struct app_level {
    using enum logging::level;
    constexpr static auto APP1 = USER1;
};
#define LOG_APP1(...) CIB_LOG_WITH_LEVEL(app_level::APP1 __VA_OPT__(, ) __VA_ARGS__)

// a wholly separate enum works too, but teach the fmt backend to print it:
namespace logging {
template <custom::level L>
constexpr auto format_as(level_wrapper<L>) -> std::string_view { /* … */ }
}
// or rename a stock level:
template <> constexpr std::string_view logging::level_text<MY_LEVEL> = "MY_LEVEL";

The environment

Every call site carries a compile-time map from query objects to values. The backend reads what it needs from it. Because the environment is a local typedef that the macros redefine, it follows ordinary scoping: namespace, class, function, block.

namespace uart {
CIB_LOG_MODULE("uart");                       // this namespace

struct rx {
    CIB_LOG_MODULE("uart.rx");                // this class

    static auto irq() -> void {
        CIB_LOG_MODULE("uart.rx.irq");        // this function
        CIB_INFO("overrun");                  // module: uart.rx.irq
    }
};

auto f() -> void {
    CIB_INFO("open");                         // module: uart
    CIB_WITH_LOG_ENV(logging::get_module, "probe") {
        CIB_INFO("probing");                  // module: probe
    }
    CIB_INFO("done");                         // module: uart again
}
} // namespace uart

Call-site bench

Pick what the environment carries and see what each backend produces. The MIPI field positions and the fmt line format are those the verification build emitted.

What’s formatted when

Everything that can be folded into the string at compile time is. Only genuinely runtime values travel as arguments. This is what keeps binary log payloads small, and it means a constexpr value costs nothing extra to log.

Types are formatted too, as their names. The backend receives a stdx::format_result: fr.str is a type carrying the string, fr.args a tuple of what’s left.

Backends

fmt

     134us INFO [default]: hello 42

Microseconds since the logger’s first use, right-aligned in eight columns, then level, module, and the message, one line each. Construct the config with several destinations to fan out; each gets identical bytes. The repo’s tests assert that logging performs no dynamic allocation. Runtime enum arguments print as their underlying value unless you give them a format_as.

Your own

struct my_config {
    struct {
        template <typename Env, typename File, typename Line, typename FR>
        auto log(File file, Line line, FR const &fr) -> void {
            constexpr auto level = logging::get_level(Env{});
            constexpr auto module = logging::get_module(Env{});
            constexpr auto fmtstr = std::string_view{decltype(fr.str)::value};
            fr.args.apply([&](auto const &...args) {
                ::fmt::print(fmtstr, args...);   // or write to RTT, a ring buffer…
            });
        }
    } logger;
};
template <> inline auto logging::config<> = my_config{};

Add an optional log_version<Env, BuildId, String>() member to handle version messages yourself.

The binary logger

On a constrained target, the strings are the expensive part of logging. The binary backend keeps each string’s characters in a type, asks a function template for that type’s ID, and sends only the ID and the runtime arguments. The image contains no log text at all.

Packets

Runtime arguments must be logging::packable: integral, floating point or enum, at most eight bytes. Strings and pointers are rejected at compile time — format them at compile time, or send an ID. Each destination is written inside conc::call_in_critical_section, so freestanding targets must specialize conc::injected_policy<>.

The catalog build

catalog<Message>() and module<Module>() are declared but never defined. An application that logs therefore has undefined symbols whose mangled names contain the string data. The build turns those into IDs:

add_library(app_lib lib.cpp)
target_link_libraries(app_lib PRIVATE cib_log_binary)

gen_str_catalog(
    OUTPUT_CPP  ${CMAKE_CURRENT_BINARY_DIR}/strings.cpp
    OUTPUT_JSON ${CMAKE_CURRENT_BINARY_DIR}/strings.json
    OUTPUT_XML  ${CMAKE_CURRENT_BINARY_DIR}/strings.xml
    INPUT_LIBS  app_lib
    STABLE_JSON stable_strings.json    # usually the previous build's strings.json
    OUTPUT_LIB  app_strings)

add_executable(app main.cpp)                    # stub: just calls into app_lib
target_link_libraries(app app_lib app_strings)

To pin one call site’s ID, put it in the environment: CIB_WITH_LOG_ENV(logging::get_string_id, 1337) { CIB_INFO("Hello"); }. The generator honors it. The same works for get_module_id.

Decoding

python3 python/cib/log_decode.py --input log.bin --json strings.json

The decoder reads short32, catalog and short64 messages, and restores module names, argument values and enum names from the collateral. Archive strings.json with every image you ship, or its logs become unreadable.

Flavors: several backends at once

logging::config<> takes type arguments. A flavor in the environment selects which specialization a call site uses, so secure logs can go somewhere else entirely.

struct secure_t;

template <> inline auto logging::config<> =
    logging::fmt::config{std::ostream_iterator<char>(std::cout)};
template <> inline auto logging::config<secure_t> =
    logging::fmt::config{secure_file_output()};

#define SECURE_LOG_WITH_LEVEL(LEVEL, ...)                                      \
    logging::log<stdx::extend_env_t<cib_log_env_t, logging::get_level, LEVEL,  \
                                    logging::get_flavor,                       \
                                    stdx::type_identity<secure_t>{}>>(         \
        __FILE__, __LINE__, STDX_CT_FORMAT(__VA_ARGS__))
#define SECURE_INFO(...) SECURE_LOG_WITH_LEVEL(logging::level::INFO __VA_OPT__(, ) __VA_ARGS__)

Flavors are also how one test binary can drive several backends: the verification program runs a capturing logger, the fmt logger and the binary logger side by side.

Version logging

struct my_version_config {
    constexpr static auto build_id = std::uint64_t{0x1234};
    constexpr static auto version_string = stdx::ct_string{"v1.2.3"};
};
template <> inline auto version::config<> = my_version_config{};

CIB_LOG_VERSION();      // default flavor
CIB_LOG_V(secure_t);    // a specific flavor

If the backend provides log_version<Env, BuildId, String>(), that is called; the binary backend builds a compact32 message (build ID up to 22 bits, empty string), a compact64 (up to 54 bits) or the byte-based long message that carries the string. Otherwise the message is logged as ordinary text at level MAX; the verification build produced Version: 4660 (v1.2.3), with the build ID in decimal.

Working with the rest of cib

Use cases

Asserting on logs in tests

struct capture_handler {
    template <typename Env, typename File, typename Line, typename FR>
    auto log(File, Line, FR const &fr) -> void {
        caps.push_back({std::string_view{decltype(fr.str)::value},
                        std::string_view{logging::get_module(Env{})},
                        logging::get_level(Env{})});
    }
};
struct capture_config { capture_handler logger; };
template <> inline auto logging::config<> = capture_config{};

Simpler still for text assertions: point the fmt backend at a std::string with std::back_inserter and search it.

A module per subsystem

Put CIB_LOG_MODULE("uart") at the top of the subsystem’s namespace. Every log inside inherits it, the decoder groups by it, and no call site has to repeat itself.

Telling instances apart

Module is compile-time. For “which of the four SPI controllers is this”, use the unit query, which takes a callable evaluated at log time: CIB_LOG_ENV(logging::get_unit, [] { return my_unit; });. It rides in four bits of the packet.

Logging from an ISR

Prefer the binary backend: no formatting and no allocation at runtime, and one short critical section per destination. Keep arguments packable. If the destination can block, give ISR logs their own flavor writing into a lock-free buffer that a lower-priority flow drains.

Keeping IDs stable across releases

Commit each build’s strings.json and feed it back as STABLE_JSON. Unchanged strings keep their IDs, so an old decoder still reads new logs. Use RESERVED_IDS to protect ranges that other tools assign.

Two channels, different destinations

Flavors (§8): normal logs to the console, secure logs to encrypted storage, with separate macros so a call site can’t pick the wrong one by accident.

Diagnostics

Pitfalls