diff --git a/AGENTS.md b/AGENTS.md index 366d95af..546de477 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -230,11 +230,54 @@ with the same library loaded elsewhere in the host process. Code should be easy to read and understand. If a sacrifice is made for performance or readability, it should be documented. -Adhere to clang-format checks configured in `.clang-format`. Run `./scripts/clang-format.sh` if needed to confirm code styling, and `./scripts/clang-format.sh --fix` to auto-format generated code created. +#### Formatting (clang-format) -### Static Analysis +The repo enforces `.clang-format` in CI (see `.github/workflows/builds.yml` → +`clang-format` job). Any divergence fails the build. -Adhere to clang-tidy checks configured in `.clang-tidy`. Run `./scripts/clang-tidy.sh` if needed to confirm code quality. +**Required workflow when generating or editing C/C++ code:** + +1. After completing a set of edits to any `.c`, `.cc`, `.cpp`, `.cxx`, `.h`, + `.hpp`, or `.hxx` file under `src/`, `include/`, or `benchmarks/`, run: + + ```bash + ./scripts/clang-format.sh --fix + ``` + + Pass the explicit paths so the run is fast; omit them only when doing a + sweep over the entire tree. +2. If clang-format reports any rewrites, treat the rewritten contents as the + final state and re-read the file before doing any further edits to it. +3. Do not commit, hand off, or declare a task complete with un-formatted + code. CI will reject it and the round-trip wastes time. + +`./scripts/clang-format.sh` (no `--fix`) runs in dry-run / `--Werror` mode and +is what CI uses; it exits non-zero on any divergence. + +#### Static Analysis (clang-tidy) + +The repo enforces `.clang-tidy` in CI (see `.github/workflows/builds.yml` → +`clang-tidy` job, run with `--fail-on-warning`). Any new warning fails the +build. + +**Required workflow when generating or editing C/C++ code:** + +1. After substantive C/C++ edits — especially anything that adds new + identifiers, new enums, new public API, new free functions, or that + touches the FFI / threading boundary — run: + + ```bash + ./scripts/clang-tidy.sh + ``` + + This requires a prior `./build.sh release` (or + `./build.sh release-tests` / `release-all`) so that + `build-release/compile_commands.json` and the generated protobuf headers + exist. +2. Address any new findings introduced by your edits. Do not introduce new + `// NOLINT` suppressions without a one-line comment explaining *why*. +3. Pre-existing findings in code you did not touch are out of scope unless + the user explicitly asks for a sweep. ## Dependencies diff --git a/client-sdk-rust b/client-sdk-rust index 8d4d069a..b7d8d12a 160000 --- a/client-sdk-rust +++ b/client-sdk-rust @@ -1 +1 @@ -Subproject commit 8d4d069ac6b47e610160bf44b8891a730ce91154 +Subproject commit b7d8d12a0fdd75d2a9cf3279b93ddd62adff2beb diff --git a/include/livekit/livekit.h b/include/livekit/livekit.h index f7906c42..a60b4a25 100644 --- a/include/livekit/livekit.h +++ b/include/livekit/livekit.h @@ -43,7 +43,8 @@ namespace livekit { /// The log sink to use for SDK messages. -enum class LogSink { +/// @deprecated Use livekit::setLogCallback instead to register a custom log callback +enum class [[deprecated("Use livekit::setLogCallback instead to register a custom log callback")]] LogSink { /// Log messages to the console. kConsole = 0, /// Log messages to a callback function. @@ -60,7 +61,18 @@ enum class LogSink { /// @param log_sink The log sink to use for SDK messages (default: Console). /// @returns true if initialization happened on this call, false if it was /// already initialized. -LIVEKIT_API bool initialize(const LogLevel& level = LogLevel::Info, const LogSink& log_sink = LogSink::kConsole); +/// @deprecated Use livekit::setLogCallback instead to register a custom log callback +[[deprecated("Use livekit::setLogCallback instead to register a custom log callback")]] LIVEKIT_API bool initialize( + const LogLevel& level, const LogSink& log_sink); + +/// Initialize the LiveKit SDK. +/// +/// This **must be the first LiveKit API called** in the process. +/// It configures global SDK state. +/// +/// @param level Minimum log level for SDK messages (default: Info). +/// Use setLogLevel() to change at runtime. +LIVEKIT_API bool initialize(const LogLevel& level = LogLevel::Info); /// Shut down the LiveKit SDK. /// diff --git a/src/ffi_client.cpp b/src/ffi_client.cpp index bd982de1..8bffd5b2 100644 --- a/src/ffi_client.cpp +++ b/src/ffi_client.cpp @@ -17,6 +17,7 @@ #include "ffi_client.h" #include +#include #include "data_track.pb.h" #include "e2ee.pb.h" @@ -219,6 +220,23 @@ proto::FfiResponse FfiClient::sendRequest(const proto::FfiRequest& request) cons return response; } +LogLevel toSpdlogLevel(proto::LogLevel level) { + switch (level) { + case proto::LOG_ERROR: + return LogLevel::Error; + case proto::LOG_WARN: + return LogLevel::Warn; + case proto::LOG_INFO: + return LogLevel::Info; + case proto::LOG_DEBUG: + return LogLevel::Debug; + case proto::LOG_TRACE: + return LogLevel::Trace; + default: + return LogLevel::Info; + } +} + void FfiClient::PushEvent(const proto::FfiEvent& event) const { std::unique_ptr to_complete; std::vector listeners_copy; @@ -251,11 +269,29 @@ void FfiClient::PushEvent(const proto::FfiEvent& event) const { } } -void LivekitFfiCallback(const uint8_t* buf, size_t len) { +extern "C" LIVEKIT_INTERNAL_API void LivekitFfiCallback(const uint8_t* buf, size_t len) { proto::FfiEvent event; event.ParseFromArray(buf, static_cast(len)); // TODO: this fixes for now, what if len exceeds int? + // Forward any FFI logs to the SDK logger + if (event.has_logs()) { + // Note: explicitly acquiring the logger here to avoid mutex acquires per-message + auto logger = detail::getLogger(); + for (const auto& rec : event.logs().records()) { + detail::forwardFfiLog(logger, toSpdlogLevel(rec.level()), rec.target(), rec.message()); + } + return; // No need to queue the log event from here + } + + // We are in a unrecoverable state, terminate the process + // This is what Python does, may not make sense for C++ + if (event.has_panic()) { + std::cerr << "FFI Panic: " << event.panic().message() << '\n'; + std::raise(SIGTERM); + return; + } + FfiClient::instance().PushEvent(event); } diff --git a/src/ffi_client.h b/src/ffi_client.h index d16f3d90..e9bd3e3c 100644 --- a/src/ffi_client.h +++ b/src/ffi_client.h @@ -58,7 +58,7 @@ extern "C" void livekit_ffi_initialize(FfiCallbackFn cb, bool capture_logs, cons extern "C" void livekit_ffi_dispose(); -extern "C" void LivekitFfiCallback(const uint8_t* buf, size_t len); +extern "C" LIVEKIT_INTERNAL_API void LivekitFfiCallback(const uint8_t* buf, size_t len); // The FfiClient is used to communicate with the FFI interface of the Rust SDK // We use the generated protocol messages to facilitate the communication. diff --git a/src/livekit.cpp b/src/livekit.cpp index 1417213e..9b05552b 100644 --- a/src/livekit.cpp +++ b/src/livekit.cpp @@ -22,14 +22,17 @@ namespace livekit { bool initialize(const LogLevel& level, const LogSink& log_sink) { + (void)log_sink; + return initialize(level); +} + +bool initialize(const LogLevel& level) { // Initializes logger if singleton instance is not already initialized setLogLevel(level); auto& ffi_client = FfiClient::instance(); - return ffi_client.initialize(log_sink == LogSink::kCallback); + return ffi_client.initialize(true); } -bool isInitialized() { return FfiClient::instance().isInitialized(); } - void shutdown() { FfiClient::instance().shutdown(); detail::shutdownLogger(); diff --git a/src/lk_log.h b/src/lk_log.h index e2aa5f15..ef10880e 100644 --- a/src/lk_log.h +++ b/src/lk_log.h @@ -19,7 +19,9 @@ #include #include +#include +#include "livekit/logging.h" #include "livekit/visibility.h" namespace livekit::detail { @@ -32,6 +34,11 @@ LIVEKIT_INTERNAL_API std::shared_ptr getLogger(); /// Tears down the spdlog logger. Called by livekit::shutdown(). LIVEKIT_INTERNAL_API void shutdownLogger(); +/// Forward a single record received from the Rust FFI log bridge into the +/// supplied logger's spdlog sinks +LIVEKIT_INTERNAL_API void forwardFfiLog(const std::shared_ptr& logger, LogLevel level, + const std::string& target, const std::string& message); + } // namespace livekit::detail // Convenience macros — two-tier filtering: diff --git a/src/logging.cpp b/src/logging.cpp index 2e66e3a5..3c2332ad 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -111,6 +111,25 @@ void shutdownLogger() { } } +void forwardFfiLog(const std::shared_ptr& logger, LogLevel level, const std::string& target, + const std::string& message) { + const auto spd_level = toSpdlogLevel(level); + if (!logger->should_log(spd_level)) { + return; + } + + // Construct a log_msg directly so the Rust target survives as + // `logger_name`, instead of being collapsed into the single "livekit" + // logger name that spdlog would otherwise apply. + const spdlog::details::log_msg msg(spdlog::source_loc{}, spdlog::string_view_t{target.data(), target.size()}, + spd_level, spdlog::string_view_t{message.data(), message.size()}); + for (auto& sink : logger->sinks()) { + if (sink->should_log(spd_level)) { + sink->log(msg); + } + } +} + } // namespace detail void setLogLevel(LogLevel level) { detail::getLogger()->set_level(toSpdlogLevel(level)); } diff --git a/src/tests/unit/test_logging.cpp b/src/tests/unit/test_logging.cpp index a58dbff5..7428d0ae 100644 --- a/src/tests/unit/test_logging.cpp +++ b/src/tests/unit/test_logging.cpp @@ -15,24 +15,67 @@ */ #include +#include #include +#include #include +#include +#include +#include #include #include #include #include +#include "ffi.pb.h" +#include "ffi_client.h" +#include "livekit/ffi_handle.h" #include "lk_log.h" namespace livekit::test { +namespace { + +// Utility function to convert LogLevel to a string for debug printing +const char* logLevelName(LogLevel level) { + switch (level) { + case LogLevel::Trace: + return "TRACE"; + case LogLevel::Debug: + return "DEBUG"; + case LogLevel::Info: + return "INFO"; + case LogLevel::Warn: + return "WARN"; + case LogLevel::Error: + return "ERROR"; + case LogLevel::Critical: + return "CRITICAL"; + case LogLevel::Off: + return "OFF"; + } + return "?"; +} + +// Used to capture log records and verify them in tests +struct LogRecord { + LogLevel level; + std::string logger_name; + std::string message; +}; + +} // namespace + class LoggingTest : public ::testing::Test { protected: - void SetUp() override { livekit::initialize(); } + void SetUp() override { livekit::setLogLevel(LogLevel::Info); } void TearDown() override { livekit::setLogCallback(nullptr); + if (FfiClient::instance().isInitialized()) { + FfiClient::instance().shutdown(); + } livekit::shutdown(); } }; @@ -60,14 +103,8 @@ TEST_F(LoggingTest, DefaultLogLevelIsInfo) { EXPECT_EQ(livekit::getLogLevel(), L // --------------------------------------------------------------------------- TEST_F(LoggingTest, CallbackReceivesLogMessages) { - struct Captured { - LogLevel level; - std::string logger_name; - std::string message; - }; - std::mutex mtx; - std::vector captured; + std::vector captured; livekit::setLogCallback([&](LogLevel level, const std::string& logger_name, const std::string& message) { std::lock_guard lock(mtx); @@ -268,4 +305,131 @@ TEST_F(LoggingTest, ConcurrentLogEmissionDoesNotCrash) { EXPECT_GE(call_count.load(), kThreads * kIterations); } +// --------------------------------------------------------------------------- +// Rust FFI -> C++ log forwarding +// --------------------------------------------------------------------------- + +// Starts an async room connect so livekit-api logs INFO ("connecting to ..."). +void sendFailedConnectRequest() { + proto::FfiRequest req; + auto* connect = req.mutable_connect(); + connect->set_url("ws://127.0.0.1:7880"); + // JWT-shaped token (format only); connection is expected to fail. + connect->set_token("eyJhbGciOiJIUzI1NiJ9.eyJleHAiOjB9.x"); + connect->mutable_options()->set_connect_timeout_ms(500); + FfiClient::instance().sendRequest(req); +} + +void sendInvalidFfiRequest() { + proto::FfiRequest req; + auto* set_subscribed = req.mutable_set_subscribed(); + set_subscribed->set_subscribe(true); + set_subscribed->set_publication_handle(12345); + (void)FfiClient::instance().sendRequest(req); +} + +TEST_F(LoggingTest, RustLogsAreForwarded) { + constexpr bool kPrintLogs = false; + + livekit::shutdown(); + + std::mutex mut; + std::condition_variable cv; + std::size_t info_log_count = 0; + std::size_t warn_log_count = 0; + std::size_t debug_log_count = 0; + std::size_t error_log_count = 0; + + const auto all_rust_logs_received = [&] { + return info_log_count > 0 && debug_log_count > 0 && warn_log_count > 0 && error_log_count > 0; + }; + + livekit::setLogLevel(LogLevel::Trace); + livekit::setLogCallback([&](LogLevel level, const std::string& logger_name, const std::string& message) { + const std::scoped_lock lock(mut); + if (kPrintLogs) { + std::cout << "[Forwarded Rust log] [" << logLevelName(level) << "] [" << logger_name << "] " << message << '\n'; + } + + switch (level) { + case LogLevel::Info: + ++info_log_count; + break; + case LogLevel::Warn: + ++warn_log_count; + break; + case LogLevel::Debug: + ++debug_log_count; + break; + case LogLevel::Error: + ++error_log_count; + break; + default: + break; + } + + if (all_rust_logs_received()) { + cv.notify_all(); + } + }); + + // Stimuli: init (debug), connect (info), invalid request (error), invalid handle drop (warn). + ASSERT_TRUE(FfiClient::instance().initialize(true)); + sendFailedConnectRequest(); + ASSERT_THROW(sendInvalidFfiRequest(), std::runtime_error); + { + const FfiHandle invalid_handle(12345); + (void)invalid_handle; + } + + { + std::unique_lock lock(mut); + ASSERT_TRUE(cv.wait_for(lock, std::chrono::seconds(3), all_rust_logs_received)); + } + + EXPECT_GT(debug_log_count, 0u); + EXPECT_GT(info_log_count, 0u); + EXPECT_GT(warn_log_count, 0u); + EXPECT_GT(error_log_count, 0u); + + FfiClient::instance().shutdown(); +} + +TEST_F(LoggingTest, RustLogsAreSuppressedWhenOff) { + livekit::shutdown(); + + std::mutex mut; + std::condition_variable cv; + std::size_t log_count = 0; + + livekit::setLogLevel(LogLevel::Off); + livekit::setLogCallback([&](LogLevel, const std::string&, const std::string&) { + const std::scoped_lock lock(mut); + ++log_count; + cv.notify_all(); + }); + + // Throw in a local SDK log for good measure + LK_LOG_INFO("Should not log"); + + // Same Rust-side stimuli as RustLogsAreForwarded, but the C++ logger should filter them all. + ASSERT_TRUE(FfiClient::instance().initialize(true)); + sendFailedConnectRequest(); + ASSERT_THROW(sendInvalidFfiRequest(), std::runtime_error); + { + const FfiHandle invalid_handle(12345); + (void)invalid_handle; + } + + { + std::unique_lock lock(mut); + // Until Rust FFI supports log flushing, we need a timeout like this to ensure no logs are + // forwarded within the 1Hz threshold + EXPECT_FALSE(cv.wait_for(lock, std::chrono::seconds(2), [&] { return log_count > 0; })); + EXPECT_EQ(log_count, 0u); + } + + FfiClient::instance().shutdown(); +} + } // namespace livekit::test