diff --git a/.gitignore b/.gitignore index 4ebc57a1..8a37fba5 100644 --- a/.gitignore +++ b/.gitignore @@ -28,3 +28,4 @@ lib/ *.dylib *.dll *.exe +livekit.log diff --git a/CMakeLists.txt b/CMakeLists.txt index 1c7e1205..8a52a025 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -85,6 +85,8 @@ file(MAKE_DIRECTORY ${PROTO_BINARY_DIR}) # Livekit static protobuf. include(protobuf) +# spdlog logging library (PRIVATE dependency). +include(spdlog) # Ensure protoc executable is found. if(TARGET protobuf::protoc) set(Protobuf_PROTOC_EXECUTABLE "$") @@ -286,6 +288,7 @@ add_library(livekit SHARED src/ffi_client.cpp src/ffi_client.h src/livekit.cpp + src/logging.cpp src/local_audio_track.cpp src/remote_audio_track.cpp src/room.cpp @@ -330,6 +333,12 @@ target_link_libraries(livekit PRIVATE livekit_ffi ${LIVEKIT_PROTOBUF_TARGET} + spdlog::spdlog +) + +target_compile_definitions(livekit + PRIVATE + SPDLOG_ACTIVE_LEVEL=${_SPDLOG_ACTIVE_LEVEL} ) message(STATUS "Protobuf: version=${Protobuf_VERSION}; protoc=${Protobuf_PROTOC_EXECUTABLE}") diff --git a/README.md b/README.md index f039d418..4bc78bf7 100644 --- a/README.md +++ b/README.md @@ -218,6 +218,93 @@ On another terminal or computer, start the sender - Registers handlers for text and file streams, logs stream events, computes one-way latency, and saves the received file locally. +## Logging + +The SDK uses [spdlog](https://github.com/gabime/spdlog) internally but does +**not** expose it in public headers. All log output goes through a thin public +API in ``. + +### Two-tier filtering + +| Tier | When | How | Cost | +|------|------|-----|------| +| **Compile-time** | CMake configure | `-DLIVEKIT_LOG_LEVEL=WARN` | Zero -- calls below the level are stripped from the binary | +| **Runtime** | Any time after `initialize()` | `livekit::setLogLevel(LogLevel::Warn)` | Minimal -- a level check before formatting | + +#### Compile-time level (`LIVEKIT_LOG_LEVEL`) + +Set once when you configure CMake. Calls below this threshold are completely +removed by the preprocessor -- no format-string evaluation, no function call. + +```bash +# Development (default): keep everything available +cmake -DLIVEKIT_LOG_LEVEL=TRACE .. + +# Release: strip TRACE / DEBUG / INFO +cmake -DLIVEKIT_LOG_LEVEL=WARN .. + +# Production: only ERROR and CRITICAL survive +cmake -DLIVEKIT_LOG_LEVEL=ERROR .. +``` + +Valid values: `TRACE`, `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `OFF`. + +#### Runtime level (`setLogLevel`) + +Among the levels that survived compilation you can still filter at runtime +without rebuilding: + +```cpp +#include + +livekit::initialize(); // default level: Info +livekit::setLogLevel(livekit::LogLevel::Debug); // show more detail +livekit::setLogLevel(livekit::LogLevel::Warn); // suppress info chatter +``` + +### Custom log callback + +Replace the default stderr sink with your own handler. This is the integration +point for frameworks like ROS2 (`RCLCPP_*` macros), Android logcat, or any +structured-logging pipeline: + +```cpp +#include + +livekit::initialize(); +livekit::setLogLevel(livekit::LogLevel::Trace); + +livekit::setLogCallback( + [](livekit::LogLevel level, + const std::string &logger_name, + const std::string &message) { + // Route to your framework, e.g.: + // RCLCPP_INFO(get_logger(), "[%s] %s", logger_name.c_str(), message.c_str()); + myLogger.log(level, logger_name, message); + }); + +// Pass nullptr to restore the default stderr sink: +livekit::setLogCallback(nullptr); +``` + +See [`examples/logging_levels/custom_sinks.cpp`](examples/logging_levels/custom_sinks.cpp) +for three copy-paste-ready patterns: **file logger**, **JSON structured lines**, +and a **ROS2 bridge** that maps `LogLevel` to `RCLCPP_*` macros. + +### Available log levels + +| Level | Typical use | +|-------|-------------| +| `Trace` | Per-frame / per-packet detail (very noisy) | +| `Debug` | Diagnostic info useful during development | +| `Info` | Normal operational messages (connection, track events) | +| `Warn` | Unexpected but recoverable situations | +| `Error` | Failures that affect functionality | +| `Critical` | Unrecoverable errors | +| `Off` | Suppress all output | + +--- + ### ๐Ÿงช Integration & Stress Tests The SDK includes integration and stress tests using Google Test (gtest). diff --git a/bridge/CMakeLists.txt b/bridge/CMakeLists.txt index 393c5612..c1b23692 100644 --- a/bridge/CMakeLists.txt +++ b/bridge/CMakeLists.txt @@ -23,6 +23,7 @@ target_include_directories(livekit_bridge $ PRIVATE ${CMAKE_CURRENT_SOURCE_DIR}/src + ${LIVEKIT_ROOT_DIR}/src ) # Link against the main livekit SDK library (which transitively provides @@ -30,6 +31,13 @@ target_include_directories(livekit_bridge target_link_libraries(livekit_bridge PUBLIC livekit + PRIVATE + spdlog::spdlog +) + +target_compile_definitions(livekit_bridge + PRIVATE + SPDLOG_ACTIVE_LEVEL=${_SPDLOG_ACTIVE_LEVEL} ) if(MSVC) diff --git a/bridge/include/livekit_bridge/livekit_bridge.h b/bridge/include/livekit_bridge/livekit_bridge.h index df5f3e34..3d27dea3 100644 --- a/bridge/include/livekit_bridge/livekit_bridge.h +++ b/bridge/include/livekit_bridge/livekit_bridge.h @@ -341,7 +341,6 @@ class LiveKitBridge { std::vector> published_audio_tracks_; /// @copydoc published_audio_tracks_ std::vector> published_video_tracks_; - }; } // namespace livekit_bridge diff --git a/bridge/src/bridge_audio_track.cpp b/bridge/src/bridge_audio_track.cpp index 71803fc8..654129cc 100644 --- a/bridge/src/bridge_audio_track.cpp +++ b/bridge/src/bridge_audio_track.cpp @@ -25,9 +25,10 @@ #include "livekit/local_participant.h" #include "livekit/local_track_publication.h" -#include #include +#include "lk_log.h" + namespace livekit_bridge { BridgeAudioTrack::BridgeAudioTrack( @@ -56,7 +57,7 @@ bool BridgeAudioTrack::pushFrame(const std::vector &data, try { source_->captureFrame(frame, timeout_ms); } catch (const std::exception &e) { - std::cerr << "[BridgeAudioTrack] captureFrame error: " << e.what() << "\n"; + LK_LOG_ERROR("BridgeAudioTrack captureFrame error: {}", e.what()); return false; } return true; @@ -77,7 +78,7 @@ bool BridgeAudioTrack::pushFrame(const std::int16_t *data, try { source_->captureFrame(frame, timeout_ms); } catch (const std::exception &e) { - std::cerr << "[BridgeAudioTrack] captureFrame error: " << e.what() << "\n"; + LK_LOG_ERROR("BridgeAudioTrack captureFrame error: {}", e.what()); return false; } return true; @@ -115,8 +116,8 @@ void BridgeAudioTrack::release() { participant_->unpublishTrack(publication_->sid()); } catch (...) { // Best-effort cleanup; ignore errors during teardown - std::cerr << "[BridgeAudioTrack] unpublishTrack error, continuing with " - "cleanup\n"; + LK_LOG_WARN("BridgeAudioTrack unpublishTrack error, continuing with " + "cleanup"); } } diff --git a/bridge/src/bridge_room_delegate.h b/bridge/src/bridge_room_delegate.h index bbee0918..8f5dd311 100644 --- a/bridge/src/bridge_room_delegate.h +++ b/bridge/src/bridge_room_delegate.h @@ -39,7 +39,8 @@ class BridgeRoomDelegate : public livekit::RoomDelegate { void onTrackSubscribed(livekit::Room &room, const livekit::TrackSubscribedEvent &ev) override; - /// Forwards a track-unsubscribed event to LiveKitBridge::onTrackUnsubscribed(). + /// Forwards a track-unsubscribed event to + /// LiveKitBridge::onTrackUnsubscribed(). void onTrackUnsubscribed(livekit::Room &room, const livekit::TrackUnsubscribedEvent &ev) override; diff --git a/bridge/src/bridge_video_track.cpp b/bridge/src/bridge_video_track.cpp index 3996e612..d78d2322 100644 --- a/bridge/src/bridge_video_track.cpp +++ b/bridge/src/bridge_video_track.cpp @@ -25,9 +25,10 @@ #include "livekit/video_frame.h" #include "livekit/video_source.h" -#include #include +#include "lk_log.h" + namespace livekit_bridge { BridgeVideoTrack::BridgeVideoTrack( @@ -56,7 +57,7 @@ bool BridgeVideoTrack::pushFrame(const std::vector &rgba, try { source_->captureFrame(frame, timestamp_us); } catch (const std::exception &e) { - std::cerr << "[BridgeVideoTrack] captureFrame error: " << e.what() << "\n"; + LK_LOG_ERROR("BridgeVideoTrack captureFrame error: {}", e.what()); return false; } return true; @@ -76,7 +77,7 @@ bool BridgeVideoTrack::pushFrame(const std::uint8_t *rgba, try { source_->captureFrame(frame, timestamp_us); } catch (const std::exception &e) { - std::cerr << "[BridgeVideoTrack] captureFrame error: " << e.what() << "\n"; + LK_LOG_ERROR("BridgeVideoTrack captureFrame error: {}", e.what()); return false; } return true; @@ -114,8 +115,8 @@ void BridgeVideoTrack::release() { participant_->unpublishTrack(publication_->sid()); } catch (...) { // Best-effort cleanup; ignore errors during teardown - std::cerr << "[BridgeVideoTrack] unpublishTrack error, continuing with " - "cleanup\n"; + LK_LOG_WARN("BridgeVideoTrack unpublishTrack error, continuing with " + "cleanup"); } } diff --git a/bridge/src/livekit_bridge.cpp b/bridge/src/livekit_bridge.cpp index cfce522b..bae25c14 100644 --- a/bridge/src/livekit_bridge.cpp +++ b/bridge/src/livekit_bridge.cpp @@ -35,9 +35,10 @@ #include "livekit/video_stream.h" #include -#include #include +#include "lk_log.h" + namespace livekit_bridge { // --------------------------------------------------------------- @@ -86,7 +87,7 @@ bool LiveKitBridge::connect(const std::string &url, const std::string &token, // Initialize the LiveKit SDK (idempotent) if (!sdk_initialized_) { - livekit::initialize(livekit::LogSink::kConsole); + livekit::initialize(); sdk_initialized_ = true; } } @@ -132,8 +133,8 @@ void LiveKitBridge::disconnect() { std::lock_guard lock(mutex_); if (!connected_) { - std::cerr << "[LiveKitBridge] Attempting to disconnect an already " - "disconnected bridge. Things may not disconnect properly.\n"; + LK_LOG_WARN("Attempting to disconnect an already disconnected bridge. " + "Things may not disconnect properly."); } connected_ = false; @@ -413,12 +414,11 @@ LiveKitBridge::startAudioReader(const CallbackKey &key, livekit::AudioStream::Options opts; auto stream = livekit::AudioStream::fromTrack(track, opts); if (!stream) { - std::cerr << "[LiveKitBridge] Failed to create AudioStream for " - << key.identity << "\n"; + LK_LOG_ERROR("Failed to create AudioStream for {}", key.identity); return old_thread; } - auto stream_copy = stream; // captured by the thread + auto stream_copy = stream; ActiveReader reader; reader.audio_stream = std::move(stream); @@ -429,17 +429,15 @@ LiveKitBridge::startAudioReader(const CallbackKey &key, try { cb(ev.frame); } catch (const std::exception &e) { - std::cerr << "[LiveKitBridge] Audio callback exception: " << e.what() - << "\n"; + LK_LOG_ERROR("Audio callback exception: {}", e.what()); } } }); active_readers_[key] = std::move(reader); if (active_readers_.size() > kMaxActiveReaders) { - std::cerr << "[LiveKitBridge] More than expected active readers. Need to " - "evaluate how much to expect/support."; - "solution"; + LK_LOG_WARN("More than expected active readers. Need to evaluate how much " + "to expect/support."); } return old_thread; } @@ -457,8 +455,7 @@ LiveKitBridge::startVideoReader(const CallbackKey &key, opts.format = livekit::VideoBufferType::RGBA; auto stream = livekit::VideoStream::fromTrack(track, opts); if (!stream) { - std::cerr << "[LiveKitBridge] Failed to create VideoStream for " - << key.identity << "\n"; + LK_LOG_ERROR("Failed to create VideoStream for {}", key.identity); return old_thread; } @@ -473,16 +470,15 @@ LiveKitBridge::startVideoReader(const CallbackKey &key, try { cb(ev.frame, ev.timestamp_us); } catch (const std::exception &e) { - std::cerr << "[LiveKitBridge] Video callback exception: " << e.what() - << "\n"; + LK_LOG_ERROR("Video callback exception: {}", e.what()); } } }); active_readers_[key] = std::move(reader); if (active_readers_.size() > kMaxActiveReaders) { - std::cerr << "[LiveKitBridge] More than expected active readers. Need to " - "evaluate how much to expect/support."; + LK_LOG_WARN("More than expected active readers. Need to evaluate how much " + "to expect/support."); } return old_thread; } diff --git a/cmake/spdlog.cmake b/cmake/spdlog.cmake new file mode 100644 index 00000000..b0956b00 --- /dev/null +++ b/cmake/spdlog.cmake @@ -0,0 +1,78 @@ +# cmake/spdlog.cmake +# +# Windows: use vcpkg spdlog +# macOS/Linux: vendored spdlog via FetchContent (static library) +# +# Exposes: +# - Target spdlog::spdlog +# - LIVEKIT_SPDLOG_ACTIVE_LEVEL compile definition +# +# Compile-time log level +# ---------------------- +# LIVEKIT_LOG_LEVEL controls which LK_LOG_* calls survive compilation. +# Calls below this level are stripped entirely (zero overhead). +# Levels that survive can still be filtered at runtime via setLogLevel(). +# +# Valid values: TRACE, DEBUG, INFO, WARN, ERROR, CRITICAL, OFF +# Default: TRACE (nothing stripped -- all levels available at runtime) +# +# Example: cmake -DLIVEKIT_LOG_LEVEL=WARN ... +# -> TRACE/DEBUG/INFO calls are compiled out; WARN/ERROR/CRITICAL remain. + +set(LIVEKIT_LOG_LEVEL "TRACE" CACHE STRING + "Compile-time minimum log level (TRACE, DEBUG, INFO, WARN, ERROR, CRITICAL, OFF)") + +# Map the user-facing name to the spdlog integer constant. +string(TOUPPER "${LIVEKIT_LOG_LEVEL}" _LK_LOG_LEVEL_UPPER) +if(_LK_LOG_LEVEL_UPPER STREQUAL "TRACE") + set(_SPDLOG_ACTIVE_LEVEL 0) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "DEBUG") + set(_SPDLOG_ACTIVE_LEVEL 1) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "INFO") + set(_SPDLOG_ACTIVE_LEVEL 2) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "WARN") + set(_SPDLOG_ACTIVE_LEVEL 3) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "ERROR") + set(_SPDLOG_ACTIVE_LEVEL 4) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "CRITICAL") + set(_SPDLOG_ACTIVE_LEVEL 5) +elseif(_LK_LOG_LEVEL_UPPER STREQUAL "OFF") + set(_SPDLOG_ACTIVE_LEVEL 6) +else() + message(FATAL_ERROR + "Invalid LIVEKIT_LOG_LEVEL='${LIVEKIT_LOG_LEVEL}'. " + "Must be one of: TRACE, DEBUG, INFO, WARN, ERROR, CRITICAL, OFF") +endif() + +message(STATUS "LiveKit compile-time log level: ${_LK_LOG_LEVEL_UPPER} (SPDLOG_ACTIVE_LEVEL=${_SPDLOG_ACTIVE_LEVEL})") + +include(FetchContent) + +set(LIVEKIT_SPDLOG_VERSION "1.15.1" CACHE STRING "Vendored spdlog version") + +# --------------------------------------------------------------------------- +# Windows: use vcpkg +# --------------------------------------------------------------------------- +if(WIN32 AND LIVEKIT_USE_VCPKG) + find_package(spdlog CONFIG REQUIRED) + message(STATUS "Windows: using vcpkg spdlog") + return() +endif() + +# --------------------------------------------------------------------------- +# macOS/Linux: vendored spdlog via FetchContent +# --------------------------------------------------------------------------- +FetchContent_Declare( + livekit_spdlog + URL "https://github.com/gabime/spdlog/archive/refs/tags/v${LIVEKIT_SPDLOG_VERSION}.tar.gz" + DOWNLOAD_EXTRACT_TIMESTAMP TRUE +) + +set(SPDLOG_BUILD_SHARED OFF CACHE BOOL "" FORCE) +set(SPDLOG_BUILD_EXAMPLE OFF CACHE BOOL "" FORCE) +set(SPDLOG_BUILD_TESTS OFF CACHE BOOL "" FORCE) +set(SPDLOG_INSTALL OFF CACHE BOOL "" FORCE) + +FetchContent_MakeAvailable(livekit_spdlog) + +message(STATUS "macOS/Linux: using vendored spdlog v${LIVEKIT_SPDLOG_VERSION}") diff --git a/examples/CMakeLists.txt b/examples/CMakeLists.txt index 5494a4b5..68ea1014 100644 --- a/examples/CMakeLists.txt +++ b/examples/CMakeLists.txt @@ -30,6 +30,9 @@ set(EXAMPLES_PRIVATE_INCLUDE_DIRS ${LIVEKIT_BINARY_DIR}/generated ) +# Propagate the compile-time log level to all example targets. +add_compile_definitions(SPDLOG_ACTIVE_LEVEL=${_SPDLOG_ACTIVE_LEVEL}) + # Shared example code (SDL media, wav source, etc.) set(EXAMPLES_COMMON_DIR ${CMAKE_CURRENT_SOURCE_DIR}/common) @@ -56,6 +59,7 @@ target_include_directories(SimpleRoom PRIVATE target_link_libraries(SimpleRoom PRIVATE livekit + spdlog::spdlog SDL3::SDL3 ) @@ -110,6 +114,7 @@ target_link_libraries(SimpleRpc PRIVATE nlohmann_json::nlohmann_json livekit + spdlog::spdlog ) # --- SimpleRobot example (robot + human executables with shared json_utils) --- @@ -140,6 +145,7 @@ target_link_libraries(SimpleRobot PRIVATE simple_robot_json_utils livekit + spdlog::spdlog ) add_executable(SimpleHuman @@ -152,6 +158,32 @@ target_link_libraries(SimpleHuman PRIVATE simple_robot_json_utils livekit + spdlog::spdlog +) + +# --- LoggingLevelsBasicUsage example --- + +add_executable(LoggingLevelsBasicUsage + logging_levels/basic_usage.cpp +) + +target_include_directories(LoggingLevelsBasicUsage PRIVATE ${EXAMPLES_PRIVATE_INCLUDE_DIRS}) + +target_link_libraries(LoggingLevelsBasicUsage + PRIVATE + livekit + spdlog::spdlog +) + +# --- LoggingLevelsCustomSinks example --- + +add_executable(LoggingLevelsCustomSinks + logging_levels/custom_sinks.cpp +) + +target_link_libraries(LoggingLevelsCustomSinks + PRIVATE + livekit ) # --- SimpleDataStream example --- @@ -165,6 +197,7 @@ target_include_directories(SimpleDataStream PRIVATE ${EXAMPLES_PRIVATE_INCLUDE_D target_link_libraries(SimpleDataStream PRIVATE livekit + spdlog::spdlog ) add_custom_command( @@ -186,7 +219,7 @@ target_include_directories(BridgeRobot PRIVATE ${EXAMPLES_PRIVATE_INCLUDE_DIRS} ${EXAMPLES_COMMON_DIR} ) -target_link_libraries(BridgeRobot PRIVATE livekit_bridge SDL3::SDL3) +target_link_libraries(BridgeRobot PRIVATE livekit_bridge spdlog::spdlog SDL3::SDL3) add_executable(BridgeHuman bridge_human_robot/human.cpp @@ -197,7 +230,7 @@ target_include_directories(BridgeHuman PRIVATE ${EXAMPLES_PRIVATE_INCLUDE_DIRS} ${EXAMPLES_COMMON_DIR} ) -target_link_libraries(BridgeHuman PRIVATE livekit_bridge SDL3::SDL3) +target_link_libraries(BridgeHuman PRIVATE livekit_bridge spdlog::spdlog SDL3::SDL3) # Copy SDL3 shared library to bridge_human_robot example output directories if(UNIX AND NOT APPLE) @@ -236,7 +269,7 @@ if(WIN32) ) # Copy DLLs to each example's output directory - foreach(EXAMPLE SimpleRoom SimpleRpc SimpleRobot SimpleHuman SimpleDataStream BridgeRobot BridgeHuman) + foreach(EXAMPLE SimpleRoom SimpleRpc SimpleRobot SimpleHuman SimpleDataStream LoggingLevelsBasicUsage LoggingLevelsCustomSinks BridgeRobot BridgeHuman) foreach(DLL ${REQUIRED_DLLS}) add_custom_command(TARGET ${EXAMPLE} POST_BUILD COMMAND ${CMAKE_COMMAND} -E copy_if_different @@ -271,7 +304,7 @@ if(UNIX) endif() # Copy shared library to each example's output directory - foreach(EXAMPLE SimpleRoom SimpleRpc SimpleRobot SimpleHuman SimpleDataStream BridgeRobot BridgeHuman) + foreach(EXAMPLE SimpleRoom SimpleRpc SimpleRobot SimpleHuman SimpleDataStream LoggingLevelsBasicUsage LoggingLevelsCustomSinks BridgeRobot BridgeHuman) add_custom_command(TARGET ${EXAMPLE} POST_BUILD COMMAND ${CMAKE_COMMAND} -E copy_if_different "${LIVEKIT_LIB_DIR}/${FFI_SHARED_LIB}" diff --git a/examples/bridge_human_robot/human.cpp b/examples/bridge_human_robot/human.cpp index 3a9c8594..25fca366 100644 --- a/examples/bridge_human_robot/human.cpp +++ b/examples/bridge_human_robot/human.cpp @@ -43,6 +43,7 @@ * Run alongside the "robot" example (which publishes with identity "robot"). */ +#include "lk_log.h" #include "livekit/audio_frame.h" #include "livekit/track.h" #include "livekit/video_frame.h" @@ -139,7 +140,7 @@ int main(int argc, char *argv[]) { // ----- Initialize SDL3 ----- if (!SDL_Init(SDL_INIT_VIDEO | SDL_INIT_AUDIO)) { - std::cerr << "[human] SDL_Init failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("[human] SDL_Init failed: {}", SDL_GetError()); return 1; } @@ -150,15 +151,14 @@ int main(int argc, char *argv[]) { SDL_Window *window = SDL_CreateWindow("Human - Robot Camera Feed", kWindowWidth, kWindowHeight, 0); if (!window) { - std::cerr << "[human] SDL_CreateWindow failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("[human] SDL_CreateWindow failed: {}", SDL_GetError()); SDL_Quit(); return 1; } SDL_Renderer *renderer = SDL_CreateRenderer(window, nullptr); if (!renderer) { - std::cerr << "[human] SDL_CreateRenderer failed: " << SDL_GetError() - << "\n"; + LK_LOG_ERROR("[human] SDL_CreateRenderer failed: {}", SDL_GetError()); SDL_DestroyWindow(window); SDL_Quit(); return 1; @@ -181,7 +181,7 @@ int main(int argc, char *argv[]) { livekit::RoomOptions options; options.auto_subscribe = true; if (!bridge.connect(url, token, options)) { - std::cerr << "[human] Failed to connect.\n"; + LK_LOG_ERROR("[human] Failed to connect."); SDL_DestroyRenderer(renderer); SDL_DestroyWindow(window); SDL_Quit(); @@ -202,7 +202,7 @@ int main(int argc, char *argv[]) { speaker = std::make_unique(frame.sample_rate(), frame.num_channels()); if (!speaker->init()) { - std::cerr << "[human] Failed to init SDL speaker.\n"; + LK_LOG_ERROR("[human] Failed to init SDL speaker."); speaker.reset(); return; } @@ -331,8 +331,7 @@ int main(int argc, char *argv[]) { texture = SDL_CreateTexture(renderer, SDL_PIXELFORMAT_RGBA32, SDL_TEXTUREACCESS_STREAMING, fw, fh); if (!texture) { - std::cerr << "[human] SDL_CreateTexture failed: " << SDL_GetError() - << "\n"; + LK_LOG_ERROR("[human] SDL_CreateTexture failed: {}", SDL_GetError()); } tex_width = fw; tex_height = fh; diff --git a/examples/bridge_human_robot/robot.cpp b/examples/bridge_human_robot/robot.cpp index 6c467e21..9a2229df 100644 --- a/examples/bridge_human_robot/robot.cpp +++ b/examples/bridge_human_robot/robot.cpp @@ -30,6 +30,7 @@ * Run alongside the "human" example (which displays the robot's feed). */ +#include "lk_log.h" #include "livekit/audio_frame.h" #include "livekit/track.h" #include "livekit/video_frame.h" @@ -319,7 +320,7 @@ int main(int argc, char *argv[]) { // ----- Initialize SDL3 ----- if (!SDL_Init(SDL_INIT_VIDEO | SDL_INIT_AUDIO | SDL_INIT_CAMERA)) { - std::cerr << "[robot] SDL_Init failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("[robot] SDL_Init failed: {}", SDL_GetError()); return 1; } @@ -329,7 +330,7 @@ int main(int argc, char *argv[]) { livekit::RoomOptions options; options.auto_subscribe = true; if (!bridge.connect(url, token, options)) { - std::cerr << "[robot] Failed to connect.\n"; + LK_LOG_ERROR("[robot] Failed to connect."); SDL_Quit(); return 1; } @@ -379,7 +380,7 @@ int main(int argc, char *argv[]) { [&mic](const int16_t *samples, int num_samples_per_channel, int /*sample_rate*/, int /*num_channels*/) { if (!mic->pushFrame(samples, num_samples_per_channel)) { - std::cerr << "[robot] Mic track released.\n"; + LK_LOG_WARN("[robot] Mic track released."); } }); @@ -393,7 +394,7 @@ int main(int argc, char *argv[]) { } }); } else { - std::cerr << "[robot] SDL mic init failed.\n"; + LK_LOG_ERROR("[robot] SDL mic init failed."); sdl_mic.reset(); } } @@ -443,7 +444,7 @@ int main(int argc, char *argv[]) { if (!cam->pushFrame( buf.data(), buf.size(), static_cast(timestampNS / 1000))) { - std::cerr << "[robot] Cam track released.\n"; + LK_LOG_WARN("[robot] Cam track released."); } }); @@ -457,7 +458,7 @@ int main(int argc, char *argv[]) { } }); } else { - std::cerr << "[robot] SDL camera init failed.\n"; + LK_LOG_ERROR("[robot] SDL camera init failed."); sdl_cam.reset(); } } diff --git a/examples/common/sdl_media.cpp b/examples/common/sdl_media.cpp index 4961f513..6975aca0 100644 --- a/examples/common/sdl_media.cpp +++ b/examples/common/sdl_media.cpp @@ -16,7 +16,7 @@ #include "sdl_media.h" -#include +#include "lk_log.h" // ---------------------- SDLMicSource ----------------------------- @@ -48,13 +48,12 @@ bool SDLMicSource::init() { nullptr); if (!stream_) { - std::cerr << "Failed to open recording stream: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("Failed to open recording stream: {}", SDL_GetError()); return false; } if (!SDL_ResumeAudioStreamDevice(stream_)) { // unpause device - std::cerr << "Failed to resume recording device: " << SDL_GetError() - << "\n"; + LK_LOG_ERROR("Failed to resume recording device: {}", SDL_GetError()); return false; } @@ -125,12 +124,12 @@ bool DDLSpeakerSink::init() { nullptr); if (!stream_) { - std::cerr << "Failed to open playback stream: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("Failed to open playback stream: {}", SDL_GetError()); return false; } if (!SDL_ResumeAudioStreamDevice(stream_)) { - std::cerr << "Failed to resume playback device: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("Failed to resume playback device: {}", SDL_GetError()); return false; } @@ -147,7 +146,7 @@ void DDLSpeakerSink::enqueue(const int16_t *samples, // SDL will resample / convert as needed on SDL_GetAudioStreamData() side. if (!SDL_PutAudioStreamData(stream_, samples, bytes)) { - std::cerr << "SDL_PutAudioStreamData failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDL_PutAudioStreamData failed: {}", SDL_GetError()); } } @@ -182,7 +181,7 @@ bool SDLCamSource::init() { int count = 0; SDL_CameraID *cams = SDL_GetCameras(&count); // if (!cams || count == 0) { - std::cerr << "No cameras available: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("No cameras available: {}", SDL_GetError()); if (cams) SDL_free(cams); return false; @@ -201,7 +200,7 @@ bool SDLCamSource::init() { camera_ = SDL_OpenCamera(camId, &spec_); if (!camera_) { - std::cerr << "Failed to open camera: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("Failed to open camera: {}", SDL_GetError()); return false; } diff --git a/examples/common/sdl_media_manager.cpp b/examples/common/sdl_media_manager.cpp index ac6dad7a..1c4eaf4b 100644 --- a/examples/common/sdl_media_manager.cpp +++ b/examples/common/sdl_media_manager.cpp @@ -17,11 +17,11 @@ #include "sdl_media_manager.h" #include "fallback_capture.h" +#include "lk_log.h" #include "livekit/livekit.h" #include "sdl_media.h" #include "sdl_video_renderer.h" #include -#include #include using namespace livekit; @@ -39,8 +39,8 @@ bool SDLMediaManager::ensureSDLInit(Uint32 flags) { return true; // already init } if (!SDL_InitSubSystem(flags)) { - std::cerr << "SDL_InitSubSystem failed (flags=" << flags - << "): " << SDL_GetError() << std::endl; + LK_LOG_ERROR("SDL_InitSubSystem failed (flags={}): {}", flags, + SDL_GetError()); return false; } return true; @@ -53,7 +53,7 @@ bool SDLMediaManager::startMic( stopMic(); if (!audio_source) { - std::cerr << "startMic: audioSource is null\n"; + LK_LOG_ERROR("startMic: audioSource is null"); return false; } @@ -62,7 +62,7 @@ bool SDLMediaManager::startMic( // Try SDL path if (!ensureSDLInit(SDL_INIT_AUDIO)) { - std::cerr << "No SDL audio, falling back to noise loop.\n"; + LK_LOG_WARN("No SDL audio, falling back to noise loop."); mic_using_sdl_ = false; mic_thread_ = std::thread(runNoiseCaptureLoop, mic_source_, std::ref(mic_running_)); @@ -72,7 +72,7 @@ bool SDLMediaManager::startMic( int recCount = 0; SDL_AudioDeviceID *recDevs = SDL_GetAudioRecordingDevices(&recCount); if (!recDevs || recCount == 0) { - std::cerr << "No microphone devices found, falling back to noise loop.\n"; + LK_LOG_WARN("No microphone devices found, falling back to noise loop."); if (recDevs) SDL_free(recDevs); mic_using_sdl_ = false; @@ -97,13 +97,12 @@ bool SDLMediaManager::startMic( try { src->captureFrame(frame); } catch (const std::exception &e) { - std::cerr << "Error in captureFrame (SDL mic): " << e.what() - << std::endl; + LK_LOG_ERROR("Error in captureFrame (SDL mic): {}", e.what()); } }); if (!mic_sdl_->init()) { - std::cerr << "Failed to init SDL mic, falling back to noise loop.\n"; + LK_LOG_WARN("Failed to init SDL mic, falling back to noise loop."); mic_using_sdl_ = false; mic_sdl_.reset(); mic_thread_ = @@ -138,7 +137,7 @@ bool SDLMediaManager::startCamera( stopCamera(); if (!video_source) { - std::cerr << "startCamera: videoSource is null\n"; + LK_LOG_ERROR("startCamera: videoSource is null"); return false; } @@ -147,7 +146,7 @@ bool SDLMediaManager::startCamera( // Try SDL if (!ensureSDLInit(SDL_INIT_CAMERA)) { - std::cerr << "No SDL camera subsystem, using fake video loop.\n"; + LK_LOG_WARN("No SDL camera subsystem, using fake video loop."); cam_using_sdl_ = false; cam_thread_ = std::thread(runFakeVideoCaptureLoop, cam_source_, std::ref(cam_running_)); @@ -157,7 +156,7 @@ bool SDLMediaManager::startCamera( int camCount = 0; SDL_CameraID *cams = SDL_GetCameras(&camCount); if (!cams || camCount == 0) { - std::cerr << "No camera devices found, using fake video loop.\n"; + LK_LOG_WARN("No camera devices found, using fake video loop."); if (cams) SDL_free(cams); cam_using_sdl_ = false; @@ -187,13 +186,12 @@ bool SDLMediaManager::startCamera( src->captureFrame(frame, timestampNS / 1000, VideoRotation::VIDEO_ROTATION_0); } catch (const std::exception &e) { - std::cerr << "Error in captureFrame (SDL cam): " << e.what() - << std::endl; + LK_LOG_ERROR("Error in captureFrame (SDL cam): {}", e.what()); } }); if (!can_sdl_->init()) { - std::cerr << "Failed to init SDL camera, using fake video loop.\n"; + LK_LOG_WARN("Failed to init SDL camera, using fake video loop."); cam_using_sdl_ = false; can_sdl_.reset(); cam_thread_ = std::thread(runFakeVideoCaptureLoop, cam_source_, @@ -228,12 +226,12 @@ bool SDLMediaManager::startSpeaker( stopSpeaker(); if (!audio_stream) { - std::cerr << "startSpeaker: audioStream is null\n"; + LK_LOG_ERROR("startSpeaker: audioStream is null"); return false; } if (!ensureSDLInit(SDL_INIT_AUDIO)) { - std::cerr << "startSpeaker: SDL_INIT_AUDIO failed\n"; + LK_LOG_ERROR("startSpeaker: SDL_INIT_AUDIO failed"); return false; } @@ -246,8 +244,7 @@ bool SDLMediaManager::startSpeaker( try { speaker_thread_ = std::thread(&SDLMediaManager::speakerLoopSDL, this); } catch (const std::exception &e) { - std::cerr << "startSpeaker: failed to start speaker thread: " << e.what() - << "\n"; + LK_LOG_ERROR("startSpeaker: failed to start speaker thread: {}", e.what()); speaker_running_.store(false, std::memory_order_relaxed); speaker_stream_.reset(); return false; @@ -291,8 +288,8 @@ void SDLMediaManager::speakerLoopSDL() { /*userdata=*/nullptr); if (!localStream) { - std::cerr << "speakerLoopSDL: SDL_OpenAudioDeviceStream failed: " - << SDL_GetError() << "\n"; + LK_LOG_ERROR("speakerLoopSDL: SDL_OpenAudioDeviceStream failed: {}", + SDL_GetError()); break; } @@ -300,14 +297,14 @@ void SDLMediaManager::speakerLoopSDL() { dev = SDL_GetAudioStreamDevice(localStream); if (dev == 0) { - std::cerr << "speakerLoopSDL: SDL_GetAudioStreamDevice failed: " - << SDL_GetError() << "\n"; + LK_LOG_ERROR("speakerLoopSDL: SDL_GetAudioStreamDevice failed: {}", + SDL_GetError()); break; } if (!SDL_ResumeAudioDevice(dev)) { - std::cerr << "speakerLoopSDL: SDL_ResumeAudioDevice failed: " - << SDL_GetError() << "\n"; + LK_LOG_ERROR("speakerLoopSDL: SDL_ResumeAudioDevice failed: {}", + SDL_GetError()); break; } } @@ -317,8 +314,8 @@ void SDLMediaManager::speakerLoopSDL() { const int numBytes = static_cast(data.size() * sizeof(std::int16_t)); if (!SDL_PutAudioStreamData(localStream, data.data(), numBytes)) { - std::cerr << "speakerLoopSDL: SDL_PutAudioStreamData failed: " - << SDL_GetError() << "\n"; + LK_LOG_ERROR("speakerLoopSDL: SDL_PutAudioStreamData failed: {}", + SDL_GetError()); break; } @@ -352,12 +349,12 @@ void SDLMediaManager::stopSpeaker() { bool SDLMediaManager::initRenderer( const std::shared_ptr &video_stream) { if (!video_stream) { - std::cerr << "startRenderer: videoStream is null\n"; + LK_LOG_ERROR("startRenderer: videoStream is null"); return false; } // Ensure SDL video subsystem is initialized if (!ensureSDLInit(SDL_INIT_VIDEO)) { - std::cerr << "startRenderer: SDL_INIT_VIDEO failed\n"; + LK_LOG_ERROR("startRenderer: SDL_INIT_VIDEO failed"); return false; } renderer_stream_ = video_stream; @@ -368,7 +365,7 @@ bool SDLMediaManager::initRenderer( sdl_renderer_ = std::make_unique(); // You can tune these dimensions or even make them options if (!sdl_renderer_->init("LiveKit Remote Video", 1280, 720)) { - std::cerr << "startRenderer: SDLVideoRenderer::init failed\n"; + LK_LOG_ERROR("startRenderer: SDLVideoRenderer::init failed"); sdl_renderer_.reset(); renderer_stream_.reset(); renderer_running_.store(false, std::memory_order_relaxed); diff --git a/examples/common/sdl_video_renderer.cpp b/examples/common/sdl_video_renderer.cpp index 7ba3a783..bdc989bc 100644 --- a/examples/common/sdl_video_renderer.cpp +++ b/examples/common/sdl_video_renderer.cpp @@ -16,9 +16,9 @@ #include "sdl_video_renderer.h" +#include "lk_log.h" #include "livekit/livekit.h" #include -#include using namespace livekit; @@ -35,13 +35,13 @@ bool SDLVideoRenderer::init(const char *title, int width, int height) { // Assume SDL_Init(SDL_INIT_VIDEO) already called in main() window_ = SDL_CreateWindow(title, width_, height_, 0); if (!window_) { - std::cerr << "SDL_CreateWindow failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDL_CreateWindow failed: {}", SDL_GetError()); return false; } renderer_ = SDL_CreateRenderer(window_, nullptr); if (!renderer_) { - std::cerr << "SDL_CreateRenderer failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDL_CreateRenderer failed: {}", SDL_GetError()); return false; } @@ -50,7 +50,7 @@ bool SDLVideoRenderer::init(const char *title, int width, int height) { texture_ = SDL_CreateTexture(renderer_, SDL_PIXELFORMAT_RGBA8888, SDL_TEXTUREACCESS_STREAMING, width_, height_); if (!texture_) { - std::cerr << "SDL_CreateTexture failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDL_CreateTexture failed: {}", SDL_GetError()); return false; } @@ -123,8 +123,7 @@ void SDLVideoRenderer::render() { try { frame = frame.convert(livekit::VideoBufferType::RGBA, false); } catch (const std::exception &ex) { - std::cerr << "SDLVideoRenderer: convert to RGBA failed: " << ex.what() - << "\n"; + LK_LOG_ERROR("SDLVideoRenderer: convert to RGBA failed: {}", ex.what()); return; } } @@ -144,8 +143,8 @@ void SDLVideoRenderer::render() { // compatible with Livekit RGBA format. SDL_TEXTUREACCESS_STREAMING, width_, height_); if (!texture_) { - std::cerr << "SDLVideoRenderer: SDL_CreateTexture failed: " - << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDLVideoRenderer: SDL_CreateTexture failed: {}", + SDL_GetError()); return; } } @@ -154,8 +153,8 @@ void SDLVideoRenderer::render() { void *pixels = nullptr; int pitch = 0; if (!SDL_LockTexture(texture_, nullptr, &pixels, &pitch)) { - std::cerr << "SDLVideoRenderer: SDL_LockTexture failed: " << SDL_GetError() - << "\n"; + LK_LOG_ERROR("SDLVideoRenderer: SDL_LockTexture failed: {}", + SDL_GetError()); return; } diff --git a/examples/logging_levels/README.md b/examples/logging_levels/README.md new file mode 100644 index 00000000..546318b5 --- /dev/null +++ b/examples/logging_levels/README.md @@ -0,0 +1,160 @@ +# Logging Examples + +Demonstrates the LiveKit C++ SDK's two-tier logging system. No LiveKit server +is required -- the examples simply emit log messages at every severity level so +you can see how filtering works. + +There are two executables: + +| Target | Source | What it shows | +|------------------------------|---------------------|---------------| +| `LoggingLevelsBasicUsage` | `basic_usage.cpp` | Runtime level cycling and a basic custom callback | +| `LoggingLevelsCustomSinks` | `custom_sinks.cpp` | Three practical custom sink patterns: file, JSON, and ROS2 bridge | + +## Usage -- LoggingLevelsBasicUsage + +```bash +# Full demo: cycles through every runtime level, then shows the callback API +./build/examples/LoggingLevelsBasicUsage + +# Set a single runtime level and emit all messages +./build/examples/LoggingLevelsBasicUsage warn # only WARN, ERROR, CRITICAL printed +./build/examples/LoggingLevelsBasicUsage trace # everything printed +./build/examples/LoggingLevelsBasicUsage off # nothing printed +``` + +## Usage -- LoggingLevelsCustomSinks + +```bash +# Run all three sink demos in sequence +./build/examples/LoggingLevelsCustomSinks + +# Run a single sink demo +./build/examples/LoggingLevelsCustomSinks file # writes SDK logs to livekit.log +./build/examples/LoggingLevelsCustomSinks json # emits JSON-lines to stdout +./build/examples/LoggingLevelsCustomSinks ros2 # mimics RCLCPP_* output format +``` + +## How log-level filtering works + +The SDK filters log messages in two stages: + +### 1. Compile-time (`LIVEKIT_LOG_LEVEL`) + +Set at CMake configure time. Calls **below** this level are stripped from the +binary entirely -- the format string is never evaluated and no function is +called. This is zero-cost. + +```bash +# Default: nothing stripped (all levels available at runtime) +cmake -DLIVEKIT_LOG_LEVEL=TRACE .. + +# Strip TRACE, DEBUG, and INFO at compile time +cmake -DLIVEKIT_LOG_LEVEL=WARN .. + +# Only ERROR and CRITICAL survive +cmake -DLIVEKIT_LOG_LEVEL=ERROR .. +``` + +Valid values: `TRACE`, `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, `OFF`. + +Under the hood this sets `SPDLOG_ACTIVE_LEVEL`, which the `LK_LOG_*` macros +check with a preprocessor guard before emitting any code. + +### 2. Runtime (`setLogLevel`) + +Among the levels that survived compilation, `setLogLevel()` controls which +ones actually produce output. You can change it at any time after +`livekit::initialize()`: + +```cpp +livekit::initialize(); // default level: Info +livekit::setLogLevel(livekit::LogLevel::Debug); // show more detail +livekit::setLogLevel(livekit::LogLevel::Error); // only errors and above +``` + +### Interaction between the two tiers + +| Compile-time level | Runtime level | TRACE | DEBUG | INFO | WARN | ERROR | +|--------------------|---------------|:-----:|:-----:|:----:|:----:|:-----:| +| TRACE | Info | | | x | x | x | +| TRACE | Trace | x | x | x | x | x | +| WARN | Trace | | | | x | x | +| WARN | Error | | | | | x | + +Cells marked **x** produce output. Empty cells are filtered out -- either +stripped at compile time (left columns when compile-time > level) or suppressed +at runtime. + +## Custom log callbacks (`setLogCallback`) + +`setLogCallback()` lets you redirect **all** SDK log output to your own handler +instead of the default stderr sink. This is the integration point for frameworks +like ROS2, Android logcat, or any structured-logging pipeline. + +The basic API: + +```cpp +livekit::setLogCallback( + [](livekit::LogLevel level, + const std::string &logger_name, + const std::string &message) { + // Your code here -- e.g. write to file, emit JSON, call RCLCPP_INFO, ... + }); + +// Pass nullptr to restore the default stderr sink: +livekit::setLogCallback(nullptr); +``` + +`LoggingLevelsCustomSinks` (`custom_sinks.cpp`) provides three ready-to-copy patterns: + +### File sink + +Writes every SDK log line to a file with an ISO-8601 timestamp: + +```cpp +auto file = std::make_shared("livekit.log", std::ios::trunc); +livekit::setLogCallback( + [file](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + *file << timestamp() << " [" << levelTag(level) << "] [" + << logger_name << "] " << message << "\n"; + }); +``` + +### JSON sink + +Emits one JSON object per line -- ready for piping into `jq` or a log +aggregation service: + +``` +{"ts":"2025-07-01T12:00:00.123Z","level":"INFO","logger":"livekit","msg":"track published"} +``` + +### ROS2 bridge sink + +Maps `livekit::LogLevel` to `RCLCPP_DEBUG` / `RCLCPP_INFO` / `RCLCPP_WARN` / +`RCLCPP_ERROR` so LiveKit logs appear in the standard ROS2 console output, +properly severity-tagged and namespaced under your node: + +```cpp +livekit::setLogCallback( + [node](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + switch (level) { + case livekit::LogLevel::Trace: + case livekit::LogLevel::Debug: + RCLCPP_DEBUG(node->get_logger(), "[%s] %s", + logger_name.c_str(), message.c_str()); + break; + case livekit::LogLevel::Info: + RCLCPP_INFO(node->get_logger(), "[%s] %s", + logger_name.c_str(), message.c_str()); + break; + // ... Warn, Error, Critical ... + } + }); +``` + +The example compiles without rclcpp by stubbing the output to match ROS2 +formatting. diff --git a/examples/logging_levels/basic_usage.cpp b/examples/logging_levels/basic_usage.cpp new file mode 100644 index 00000000..921d96d3 --- /dev/null +++ b/examples/logging_levels/basic_usage.cpp @@ -0,0 +1,164 @@ +/* + * Copyright 2023 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +/// @file main.cpp +/// @brief Demonstrates LiveKit SDK log-level control and custom log callbacks. +/// +/// Logging has two tiers of filtering: +/// +/// 1. **Compile-time** (LIVEKIT_LOG_LEVEL, set via CMake): +/// Calls below this level are stripped from the binary entirely. +/// Default is TRACE (nothing stripped). For a lean release build: +/// cmake -DLIVEKIT_LOG_LEVEL=WARN ... +/// +/// 2. **Runtime** (setLogLevel()): +/// Among the levels that survived compilation, setLogLevel() controls +/// which ones actually produce output. This is what this example demos. +/// +/// Usage: +/// LoggingLevels [trace|debug|info|warn|error|critical|off] +/// +/// If no argument is given, the example cycles through every level so you can +/// see which messages are filtered at each setting. + +#include "lk_log.h" +#include "livekit/livekit.h" + +#include +#include +#include +#include + +namespace { + +const char *levelName(livekit::LogLevel level) { + switch (level) { + case livekit::LogLevel::Trace: + return "TRACE"; + case livekit::LogLevel::Debug: + return "DEBUG"; + case livekit::LogLevel::Info: + return "INFO"; + case livekit::LogLevel::Warn: + return "WARN"; + case livekit::LogLevel::Error: + return "ERROR"; + case livekit::LogLevel::Critical: + return "CRITICAL"; + case livekit::LogLevel::Off: + return "OFF"; + } + return "UNKNOWN"; +} + +livekit::LogLevel parseLevel(const char *arg) { + if (std::strcmp(arg, "trace") == 0) + return livekit::LogLevel::Trace; + if (std::strcmp(arg, "debug") == 0) + return livekit::LogLevel::Debug; + if (std::strcmp(arg, "info") == 0) + return livekit::LogLevel::Info; + if (std::strcmp(arg, "warn") == 0) + return livekit::LogLevel::Warn; + if (std::strcmp(arg, "error") == 0) + return livekit::LogLevel::Error; + if (std::strcmp(arg, "critical") == 0) + return livekit::LogLevel::Critical; + if (std::strcmp(arg, "off") == 0) + return livekit::LogLevel::Off; + std::cerr << "Unknown level '" << arg + << "', defaulting to Info.\n" + << "Valid: trace, debug, info, warn, error, critical, off\n"; + return livekit::LogLevel::Info; +} + +/// Emit one message at every severity level using the LK_LOG_* macros. +void emitAllLevels() { + LK_LOG_TRACE("This is a TRACE message (very verbose internals)"); + LK_LOG_DEBUG("This is a DEBUG message (diagnostic detail)"); + LK_LOG_INFO("This is an INFO message (normal operation)"); + LK_LOG_WARN("This is a WARN message (something unexpected)"); + LK_LOG_ERROR("This is an ERROR message (something failed)"); + LK_LOG_CRITICAL("This is a CRITICAL message (unrecoverable)"); +} + +/// Demonstrate cycling through every log level. +void runLevelCycleDemo() { + const livekit::LogLevel levels[] = { + livekit::LogLevel::Trace, livekit::LogLevel::Debug, + livekit::LogLevel::Info, livekit::LogLevel::Warn, + livekit::LogLevel::Error, livekit::LogLevel::Critical, + livekit::LogLevel::Off, + }; + + for (auto level : levels) { + std::cout << "\n========================================\n" + << " Setting log level to: " << levelName(level) << "\n" + << "========================================\n"; + livekit::setLogLevel(level); + emitAllLevels(); + } +} + +/// Demonstrate a custom log callback (e.g. for ROS2 integration). +void runCallbackDemo() { + std::cout << "\n========================================\n" + << " Custom LogCallback demo\n" + << "========================================\n"; + + livekit::setLogLevel(livekit::LogLevel::Trace); + + // Install a user-defined callback that captures all log output. + // In a real ROS2 node you would replace this with RCLCPP_* macros. + livekit::setLogCallback( + [](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + std::cout << "[CALLBACK] [" << levelName(level) << "] [" << logger_name + << "] " << message << "\n"; + }); + + LK_LOG_INFO("This message is routed through the custom callback"); + LK_LOG_WARN("Warnings also go through the callback"); + LK_LOG_ERROR("Errors too -- the callback sees everything >= the level"); + + // Restore default stderr sink by passing an empty callback. + livekit::setLogCallback(nullptr); + + std::cout << "\n(Restored default stderr sink)\n"; + LK_LOG_INFO("This message goes to stderr again (default sink)"); +} + +} // namespace + +int main(int argc, char *argv[]) { + // Initialize the LiveKit SDK (creates the spdlog logger). + livekit::initialize(); + + if (argc > 1) { + // Single-level mode: set the requested level and emit all messages. + livekit::LogLevel level = parseLevel(argv[1]); + std::cout << "Setting log level to: " << levelName(level) << "\n\n"; + livekit::setLogLevel(level); + emitAllLevels(); + } else { + // Full demo: cycle through levels, then show the callback API. + runLevelCycleDemo(); + runCallbackDemo(); + } + + livekit::shutdown(); + return 0; +} diff --git a/examples/logging_levels/custom_sinks.cpp b/examples/logging_levels/custom_sinks.cpp new file mode 100644 index 00000000..c8dda21e --- /dev/null +++ b/examples/logging_levels/custom_sinks.cpp @@ -0,0 +1,294 @@ +/* + * Copyright 2023 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +/// @file custom_sinks.cpp +/// @brief Shows how SDK consumers supply their own log backend via +/// livekit::setLogCallback(). +/// +/// This example uses ONLY the public SDK API (). +/// No internal headers or spdlog dependency required. +/// +/// Three patterns are demonstrated: +/// +/// 1. **File logger** -- write SDK logs to a file on disk. +/// 2. **JSON logger** -- emit structured JSON lines (for log aggregation). +/// 3. **ROS2 bridge** -- skeleton showing how to route SDK logs into +/// RCLCPP_* macros (the rclcpp headers are stubbed +/// so this compiles without a ROS2 install). +/// +/// Usage: +/// CustomSinks [file|json|ros2] +/// +/// If no argument is given, all three sinks are demonstrated in sequence. + +#include "livekit/livekit.h" + +#include +#include +#include +#include +#include +#include + +namespace { + +// --------------------------------------------------------------- +// Helpers +// --------------------------------------------------------------- + +const char *levelTag(livekit::LogLevel level) { + switch (level) { + case livekit::LogLevel::Trace: + return "TRACE"; + case livekit::LogLevel::Debug: + return "DEBUG"; + case livekit::LogLevel::Info: + return "INFO"; + case livekit::LogLevel::Warn: + return "WARN"; + case livekit::LogLevel::Error: + return "ERROR"; + case livekit::LogLevel::Critical: + return "CRITICAL"; + case livekit::LogLevel::Off: + return "OFF"; + } + return "?"; +} + +std::string nowISO8601() { + auto now = std::chrono::system_clock::now(); + auto tt = std::chrono::system_clock::to_time_t(now); + auto ms = std::chrono::duration_cast( + now.time_since_epoch()) % + 1000; + std::ostringstream ss; + ss << std::put_time(std::gmtime(&tt), "%FT%T") << '.' << std::setfill('0') + << std::setw(3) << ms.count() << 'Z'; + return ss.str(); +} + +struct SampleLog { + livekit::LogLevel level; + const char *message; +}; + +// Representative messages that the SDK would emit during normal operation. +// We drive the installed callback directly so this example has zero internal +// dependencies -- only the public API. +const SampleLog kSampleLogs[] = { + {livekit::LogLevel::Trace, "per-frame data: pts=12345 bytes=921600"}, + {livekit::LogLevel::Debug, "negotiating codec: VP8 -> H264 fallback"}, + {livekit::LogLevel::Info, "track published: sid=TR_abc123 kind=video"}, + {livekit::LogLevel::Warn, "ICE candidate pair changed unexpectedly"}, + {livekit::LogLevel::Error, "DTLS handshake failed: timeout after 10s"}, + {livekit::LogLevel::Critical, "out of memory allocating decode buffer"}, +}; + +void driveCallback(const livekit::LogCallback &cb) { + for (const auto &entry : kSampleLogs) { + cb(entry.level, "livekit", entry.message); + } +} + +// --------------------------------------------------------------- +// 1. File logger +// --------------------------------------------------------------- + +void runFileSinkDemo() { + const char *path = "livekit.log"; + std::cout << "\n=== File sink: writing SDK logs to '" << path << "' ===\n"; + + auto file = std::make_shared(path, std::ios::trunc); + if (!file->is_open()) { + std::cerr << "Could not open " << path << " for writing\n"; + return; + } + + // The shared_ptr keeps the stream alive inside the lambda even if + // the local variable goes out of scope before the callback fires. + livekit::LogCallback fileSink = + [file](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + *file << nowISO8601() << " [" << levelTag(level) << "] [" + << logger_name << "] " << message << "\n"; + file->flush(); + }; + + // In a real app you would call: + // livekit::setLogCallback(fileSink); + // and then SDK operations (room.connect, publishTrack, ...) would route + // their internal log output through your callback automatically. + // + // Here we drive the callback directly with sample data so the example + // is self-contained and doesn't require a LiveKit server. + livekit::setLogCallback(fileSink); + driveCallback(fileSink); + livekit::setLogCallback(nullptr); + + std::cout << "Wrote " << path << " -- contents:\n\n"; + std::ifstream in(path); + std::cout << in.rdbuf() << "\n"; +} + +// --------------------------------------------------------------- +// 2. JSON structured logger +// --------------------------------------------------------------- + +std::string escapeJson(const std::string &s) { + std::string out; + out.reserve(s.size() + 8); + for (char c : s) { + switch (c) { + case '"': + out += "\\\""; + break; + case '\\': + out += "\\\\"; + break; + case '\n': + out += "\\n"; + break; + case '\r': + out += "\\r"; + break; + case '\t': + out += "\\t"; + break; + default: + out += c; + } + } + return out; +} + +void runJsonSinkDemo() { + std::cout << "\n=== JSON sink: structured log lines to stdout ===\n\n"; + + livekit::LogCallback jsonSink = + [](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + std::cout << R"({"ts":")" << nowISO8601() << R"(","level":")" + << levelTag(level) << R"(","logger":")" + << escapeJson(logger_name) << R"(","msg":")" + << escapeJson(message) << "\"}\n"; + }; + + livekit::setLogCallback(jsonSink); + driveCallback(jsonSink); + livekit::setLogCallback(nullptr); +} + +// --------------------------------------------------------------- +// 3. ROS2 bridge (stubbed -- compiles without rclcpp) +// --------------------------------------------------------------- +// +// In a real ROS2 node the lambda body would be: +// +// switch (level) { +// case livekit::LogLevel::Trace: +// case livekit::LogLevel::Debug: +// RCLCPP_DEBUG(node_->get_logger(), "[%s] %s", +// logger_name.c_str(), message.c_str()); +// break; +// case livekit::LogLevel::Info: +// RCLCPP_INFO(node_->get_logger(), "[%s] %s", +// logger_name.c_str(), message.c_str()); +// break; +// case livekit::LogLevel::Warn: +// RCLCPP_WARN(node_->get_logger(), "[%s] %s", +// logger_name.c_str(), message.c_str()); +// break; +// case livekit::LogLevel::Error: +// case livekit::LogLevel::Critical: +// RCLCPP_ERROR(node_->get_logger(), "[%s] %s", +// logger_name.c_str(), message.c_str()); +// break; +// default: +// break; +// } +// +// Here we stub it with console output that mimics ROS2 formatting. + +void runRos2SinkDemo() { + std::cout << "\n=== ROS2 bridge sink (stubbed) ===\n\n"; + + const std::string node_name = "livekit_bridge_node"; + + livekit::LogCallback ros2Sink = + [&node_name](livekit::LogLevel level, const std::string &logger_name, + const std::string &message) { + const char *ros_level; + switch (level) { + case livekit::LogLevel::Trace: + case livekit::LogLevel::Debug: + ros_level = "DEBUG"; + break; + case livekit::LogLevel::Info: + ros_level = "INFO"; + break; + case livekit::LogLevel::Warn: + ros_level = "WARN"; + break; + case livekit::LogLevel::Error: + case livekit::LogLevel::Critical: + ros_level = "ERROR"; + break; + default: + ros_level = "INFO"; + break; + } + + // Mimic: [INFO] [1719500000.123] [livekit_bridge_node]: [livekit] msg + auto epoch_s = + std::chrono::duration( + std::chrono::system_clock::now().time_since_epoch()) + .count(); + std::cout << "[" << ros_level << "] [" << std::fixed + << std::setprecision(3) << epoch_s << "] [" << node_name + << "]: [" << logger_name << "] " << message << "\n"; + }; + + livekit::setLogCallback(ros2Sink); + driveCallback(ros2Sink); + livekit::setLogCallback(nullptr); +} + +} // namespace + +int main(int argc, char *argv[]) { + livekit::initialize(); + + if (argc > 1) { + if (std::strcmp(argv[1], "file") == 0) { + runFileSinkDemo(); + } else if (std::strcmp(argv[1], "json") == 0) { + runJsonSinkDemo(); + } else if (std::strcmp(argv[1], "ros2") == 0) { + runRos2SinkDemo(); + } else { + std::cerr << "Unknown sink '" << argv[1] << "'.\n" + << "Usage: CustomSinks [file|json|ros2]\n"; + } + } else { + runFileSinkDemo(); + runJsonSinkDemo(); + runRos2SinkDemo(); + } + + livekit::shutdown(); + return 0; +} diff --git a/examples/simple_room/fallback_capture.cpp b/examples/simple_room/fallback_capture.cpp index 9d1ea98f..52ca556b 100644 --- a/examples/simple_room/fallback_capture.cpp +++ b/examples/simple_room/fallback_capture.cpp @@ -23,6 +23,7 @@ #include #include +#include "lk_log.h" #include "livekit/livekit.h" #include "wav_audio_source.h" @@ -48,7 +49,7 @@ void runNoiseCaptureLoop(const std::shared_ptr &source, try { source->captureFrame(frame); } catch (const std::exception &e) { - std::cerr << "Error in captureFrame (noise): " << e.what() << std::endl; + LK_LOG_ERROR("Error in captureFrame (noise): {}", e.what()); break; } @@ -60,7 +61,7 @@ void runNoiseCaptureLoop(const std::shared_ptr &source, try { source->clearQueue(); } catch (...) { - std::cout << "Error in clearQueue (noise)" << std::endl; + LK_LOG_WARN("Error in clearQueue (noise)"); } } @@ -110,8 +111,7 @@ void runFakeVideoCaptureLoop(const std::shared_ptr &source, // If it expects I420, pass i420 instead. source->captureFrame(frame, 0, VideoRotation::VIDEO_ROTATION_0); } catch (const std::exception &e) { - std::cerr << "Error in captureFrame (fake video): " << e.what() - << std::endl; + LK_LOG_ERROR("Error in captureFrame (fake video): {}", e.what()); break; } diff --git a/examples/simple_room/main.cpp b/examples/simple_room/main.cpp index ab86bd3a..1b9809f3 100644 --- a/examples/simple_room/main.cpp +++ b/examples/simple_room/main.cpp @@ -26,6 +26,7 @@ #include #include +#include "lk_log.h" #include "livekit/livekit.h" #include "sdl_media_manager.h" #include "wav_audio_source.h" @@ -204,14 +205,13 @@ class SimpleRoomDelegate : public livekit::RoomDelegate { opts.format = livekit::VideoBufferType::RGBA; auto video_stream = VideoStream::fromTrack(ev.track, opts); if (!video_stream) { - std::cerr << "Failed to create VideoStream for track " << track_sid - << "\n"; + LK_LOG_ERROR("Failed to create VideoStream for track {}", track_sid); return; } MainThreadDispatcher::dispatch([this, video_stream] { if (!media_.initRenderer(video_stream)) { - std::cerr << "SDLMediaManager::startRenderer failed for track\n"; + LK_LOG_ERROR("SDLMediaManager::startRenderer failed for track"); } }); } else if (ev.track && ev.track->kind() == TrackKind::KIND_AUDIO) { @@ -219,7 +219,7 @@ class SimpleRoomDelegate : public livekit::RoomDelegate { auto audio_stream = AudioStream::fromTrack(ev.track, opts); MainThreadDispatcher::dispatch([this, audio_stream] { if (!media_.startSpeaker(audio_stream)) { - std::cerr << "SDLMediaManager::startRenderer failed for track\n"; + LK_LOG_ERROR("SDLMediaManager::startSpeaker failed for track"); } }); } @@ -258,7 +258,7 @@ int main(int argc, char *argv[]) { } if (!SDL_Init(SDL_INIT_VIDEO)) { - std::cerr << "SDL_Init(SDL_INIT_VIDEO) failed: " << SDL_GetError() << "\n"; + LK_LOG_ERROR("SDL_Init(SDL_INIT_VIDEO) failed: {}", SDL_GetError()); // You can choose to exit, or run in "headless" mode without renderer. // return 1; } @@ -271,8 +271,7 @@ int main(int argc, char *argv[]) { // Handle Ctrl-C to exit the idle loop std::signal(SIGINT, handleSignal); - // Initialize the livekit with logging to console. - livekit::initialize(livekit::LogSink::kConsole); + livekit::initialize(); auto room = std::make_unique(); SimpleRoomDelegate delegate(media); room->setDelegate(&delegate); @@ -302,7 +301,7 @@ int main(int argc, char *argv[]) { bool res = room->Connect(url, token, options); std::cout << "Connect result is " << std::boolalpha << res << std::endl; if (!res) { - std::cerr << "Failed to connect to room\n"; + LK_LOG_ERROR("Failed to connect to room"); livekit::shutdown(); return 1; } @@ -349,7 +348,7 @@ int main(int argc, char *argv[]) { << "\n" << " Muted: " << std::boolalpha << audioPub->muted() << "\n"; } catch (const std::exception &e) { - std::cerr << "Failed to publish track: " << e.what() << std::endl; + LK_LOG_ERROR("Failed to publish track: {}", e.what()); } media.startMic(audioSource); @@ -377,7 +376,7 @@ int main(int argc, char *argv[]) { << "\n" << " Muted: " << std::boolalpha << videoPub->muted() << "\n"; } catch (const std::exception &e) { - std::cerr << "Failed to publish track: " << e.what() << std::endl; + LK_LOG_ERROR("Failed to publish track: {}", e.what()); } media.startCamera(videoSource); diff --git a/include/livekit/e2ee.h b/include/livekit/e2ee.h index 724fdef8..e6473ae8 100644 --- a/include/livekit/e2ee.h +++ b/include/livekit/e2ee.h @@ -149,8 +149,7 @@ class E2EEManager { private: friend class E2EEManager; - KeyProvider(std::uint64_t room_handle, - KeyProviderOptions options); + KeyProvider(std::uint64_t room_handle, KeyProviderOptions options); std::uint64_t room_handle_{0}; KeyProviderOptions options_; }; diff --git a/include/livekit/livekit.h b/include/livekit/livekit.h index dd3ba037..69e61fe8 100644 --- a/include/livekit/livekit.h +++ b/include/livekit/livekit.h @@ -26,6 +26,7 @@ #include "local_participant.h" #include "local_track_publication.h" #include "local_video_track.h" +#include "logging.h" #include "participant.h" #include "remote_participant.h" #include "remote_track_publication.h" @@ -39,12 +40,10 @@ namespace livekit { -/// Where LiveKit logs should go. -enum class LogSink { - /// Logs are printed to the default console output (FFI prints directly). +/// @deprecated Use setLogLevel() and setLogCallback() from logging.h instead. +enum class [[deprecated( + "Use setLogLevel() and setLogCallback() instead")]] LogSink { kConsole = 0, - - /// Logs are delivered to the application's FFI callback for capturing. kCallback = 1, }; @@ -53,11 +52,18 @@ enum class LogSink { /// This **must be the first LiveKit API called** in the process. /// It configures global SDK state, including log routing. /// -/// If LiveKit APIs are used before calling this function, the log -/// configuration may not take effect as expected. +/// @param level Minimum log level for SDK messages (default: Info). +/// Use setLogLevel() to change at runtime. +/// /// Returns true if initialization happened on this call, false if it was /// already initialized. -bool initialize(LogSink log_sink = LogSink::kConsole); +bool initialize(LogLevel level = LogLevel::Info); + +/// @deprecated Use initialize(LogLevel) instead. +#if defined(__GNUC__) || defined(__clang__) +__attribute__((deprecated("Use initialize(LogLevel) instead"))) +#endif +bool initialize(LogSink log_sink); /// Shut down the LiveKit SDK. /// diff --git a/include/livekit/logging.h b/include/livekit/logging.h new file mode 100644 index 00000000..9d2cc564 --- /dev/null +++ b/include/livekit/logging.h @@ -0,0 +1,63 @@ +/* + * Copyright 2023 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#pragma once + +#include +#include + +namespace livekit { + +/// Severity levels for SDK log messages. +enum class LogLevel { + Trace = 0, + Debug = 1, + Info = 2, + Warn = 3, + Error = 4, + Critical = 5, + Off = 6, +}; + +/// Set the minimum log level for the SDK logger. +/// +/// Messages below this level are discarded before reaching any sink +/// or callback. Thread-safe; may be called at any time after initialize(). +void setLogLevel(LogLevel level); + +/// Return the current minimum log level. +LogLevel getLogLevel(); + +/// Signature for a user-supplied log callback. +/// +/// @param level Severity of the message. +/// @param logger_name Name of the originating logger (e.g. "livekit"). +/// @param message Formatted log message (no trailing newline). +/// +/// The callback is invoked sequentially (never concurrently) from the +/// thread that generated the log message. Implementations must not block +/// for extended periods. +using LogCallback = + std::function; + +/// Install a custom log callback, replacing the default stderr sink. +/// +/// Pass nullptr / empty function to restore the default stderr sink. +/// Thread-safe; may be called at any time after initialize(). +void setLogCallback(LogCallback callback); + +} // namespace livekit diff --git a/include/livekit/video_frame.h b/include/livekit/video_frame.h index 2f8f80c1..d9632f30 100644 --- a/include/livekit/video_frame.h +++ b/include/livekit/video_frame.h @@ -60,7 +60,7 @@ class VideoFrame { public: VideoFrame(); VideoFrame(int width, int height, VideoBufferType type, - std::vector data); + std::vector data); virtual ~VideoFrame() = default; VideoFrame(const VideoFrame &) = delete; diff --git a/src/audio_source.cpp b/src/audio_source.cpp index 8d57b7f0..4e1a48a1 100644 --- a/src/audio_source.cpp +++ b/src/audio_source.cpp @@ -24,6 +24,7 @@ #include "ffi.pb.h" #include "ffi_client.h" #include "livekit/audio_frame.h" +#include "lk_log.h" namespace livekit { @@ -123,8 +124,7 @@ void AudioSource::captureFrame(const AudioFrame &frame, int timeout_ms) { status == std::future_status::deferred) { fut.get(); } else { // std::future_status::timeout - std::cerr << "captureAudioFrameAsync timed out after " << timeout_ms - << " ms\n"; + LK_LOG_WARN("captureAudioFrameAsync timed out after {} ms", timeout_ms); } } diff --git a/src/data_stream.cpp b/src/data_stream.cpp index 980ed725..3376466a 100644 --- a/src/data_stream.cpp +++ b/src/data_stream.cpp @@ -7,6 +7,7 @@ #include "ffi_client.h" #include "livekit/local_participant.h" +#include "lk_log.h" #include "room.pb.h" namespace livekit { @@ -295,7 +296,7 @@ void TextStreamWriter::write(const std::string &text) { for (const auto &chunk_str : splitUtf8(text, kStreamChunkSize)) { const auto *p = reinterpret_cast(chunk_str.data()); std::vector bytes(p, p + chunk_str.size()); - std::cout << "sending chunk " << std::endl; + LK_LOG_DEBUG("sending chunk"); sendChunk(bytes); } } diff --git a/src/ffi_client.cpp b/src/ffi_client.cpp index 20f26333..2cc022b8 100644 --- a/src/ffi_client.cpp +++ b/src/ffi_client.cpp @@ -15,7 +15,6 @@ */ #include -#include #include "e2ee.pb.h" #include "ffi.pb.h" @@ -27,6 +26,7 @@ #include "livekit/rpc_error.h" #include "livekit/track.h" #include "livekit_ffi.h" +#include "lk_log.h" #include "room.pb.h" #include "room_proto_converter.h" @@ -38,9 +38,8 @@ std::string bytesToString(const std::vector &b) { return std::string(reinterpret_cast(b.data()), b.size()); } -// Helper to log errors and throw inline void logAndThrow(const std::string &error_msg) { - std::cerr << "LiveKit SDK Error: " << error_msg << std::endl; + LK_LOG_ERROR("LiveKit SDK Error: {}", error_msg); throw std::runtime_error(error_msg); } diff --git a/src/livekit.cpp b/src/livekit.cpp index d8756e0e..f35fe793 100644 --- a/src/livekit.cpp +++ b/src/livekit.cpp @@ -19,14 +19,40 @@ namespace livekit { +void initializeLogger(); +void shutdownLogger(); + +bool initialize(LogLevel level) { + initializeLogger(); + setLogLevel(level); + auto &ffi_client = FfiClient::instance(); + return ffi_client.initialize(/*capture_logs=*/false); +} + +#ifdef __clang__ +#pragma clang diagnostic push +#pragma clang diagnostic ignored "-Wdeprecated-declarations" +#elif defined(__GNUC__) +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wdeprecated-declarations" +#endif + bool initialize(LogSink log_sink) { + initializeLogger(); auto &ffi_client = FfiClient::instance(); return ffi_client.initialize(log_sink == LogSink::kCallback); } +#ifdef __clang__ +#pragma clang diagnostic pop +#elif defined(__GNUC__) +#pragma GCC diagnostic pop +#endif + void shutdown() { auto &ffi_client = FfiClient::instance(); ffi_client.shutdown(); + shutdownLogger(); } } // namespace livekit \ No newline at end of file diff --git a/src/lk_log.h b/src/lk_log.h new file mode 100644 index 00000000..b993feb0 --- /dev/null +++ b/src/lk_log.h @@ -0,0 +1,58 @@ +/* + * Copyright 2023 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef LIVEKIT_LK_LOG_H +#define LIVEKIT_LK_LOG_H + +#include +#include + +namespace livekit { +namespace detail { + +/// Returns the shared "livekit" logger instance. +/// The logger is created during livekit::initialize() and lives until +/// livekit::shutdown(). Calling this before initialize() returns +/// a fallback stderr logger. +std::shared_ptr getLogger(); + +} // namespace detail +} // namespace livekit + +// Convenience macros โ€” two-tier filtering: +// +// 1. Compile-time: SPDLOG_ACTIVE_LEVEL (set via CMake LIVEKIT_LOG_LEVEL) +// strips calls below the threshold entirely โ€” zero overhead, no format +// string evaluation, no function call. +// +// 2. Runtime: livekit::setLogLevel() filters among the surviving levels. +// +// Default LIVEKIT_LOG_LEVEL is TRACE (nothing stripped). For release builds +// consider -DLIVEKIT_LOG_LEVEL=INFO or WARN to eliminate verbose calls. +#define LK_LOG_TRACE(...) \ + SPDLOG_LOGGER_TRACE(livekit::detail::getLogger(), __VA_ARGS__) +#define LK_LOG_DEBUG(...) \ + SPDLOG_LOGGER_DEBUG(livekit::detail::getLogger(), __VA_ARGS__) +#define LK_LOG_INFO(...) \ + SPDLOG_LOGGER_INFO(livekit::detail::getLogger(), __VA_ARGS__) +#define LK_LOG_WARN(...) \ + SPDLOG_LOGGER_WARN(livekit::detail::getLogger(), __VA_ARGS__) +#define LK_LOG_ERROR(...) \ + SPDLOG_LOGGER_ERROR(livekit::detail::getLogger(), __VA_ARGS__) +#define LK_LOG_CRITICAL(...) \ + SPDLOG_LOGGER_CRITICAL(livekit::detail::getLogger(), __VA_ARGS__) + +#endif /* LIVEKIT_LK_LOG_H */ diff --git a/src/logging.cpp b/src/logging.cpp new file mode 100644 index 00000000..8f4554e0 --- /dev/null +++ b/src/logging.cpp @@ -0,0 +1,154 @@ +/* + * Copyright 2023 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "livekit/logging.h" + +#include + +#include +#include +#include + +namespace livekit { +namespace { + +const char *kLoggerName = "livekit"; + +spdlog::level::level_enum toSpdlogLevel(LogLevel level) { + switch (level) { + case LogLevel::Trace: + return spdlog::level::trace; + case LogLevel::Debug: + return spdlog::level::debug; + case LogLevel::Info: + return spdlog::level::info; + case LogLevel::Warn: + return spdlog::level::warn; + case LogLevel::Error: + return spdlog::level::err; + case LogLevel::Critical: + return spdlog::level::critical; + case LogLevel::Off: + return spdlog::level::off; + } + return spdlog::level::info; +} + +LogLevel fromSpdlogLevel(spdlog::level::level_enum level) { + switch (level) { + case spdlog::level::trace: + return LogLevel::Trace; + case spdlog::level::debug: + return LogLevel::Debug; + case spdlog::level::info: + return LogLevel::Info; + case spdlog::level::warn: + return LogLevel::Warn; + case spdlog::level::err: + return LogLevel::Error; + case spdlog::level::critical: + return LogLevel::Critical; + case spdlog::level::off: + return LogLevel::Off; + default: + return LogLevel::Info; + } +} + +std::mutex &loggerMutex() { + static std::mutex mtx; + return mtx; +} + +std::shared_ptr &loggerStorage() { + static std::shared_ptr logger; + return logger; +} + +std::shared_ptr createDefaultLogger() { + auto sink = std::make_shared(); + auto logger = std::make_shared(kLoggerName, sink); + logger->set_level(spdlog::level::info); + logger->set_pattern("[%Y-%m-%d %H:%M:%S.%e] [%n] [%^%l%$] %v"); + return logger; +} + +} // namespace + +namespace detail { + +std::shared_ptr getLogger() { + std::lock_guard lock(loggerMutex()); + auto &logger = loggerStorage(); + if (!logger) { + logger = createDefaultLogger(); + spdlog::register_logger(logger); + } + return logger; +} + +} // namespace detail + +void initializeLogger() { + std::lock_guard lock(loggerMutex()); + auto &logger = loggerStorage(); + if (!logger) { + logger = createDefaultLogger(); + spdlog::register_logger(logger); + } +} + +void shutdownLogger() { + std::lock_guard lock(loggerMutex()); + auto &logger = loggerStorage(); + if (logger) { + spdlog::drop(kLoggerName); + logger.reset(); + } +} + +void setLogLevel(LogLevel level) { + detail::getLogger()->set_level(toSpdlogLevel(level)); +} + +LogLevel getLogLevel() { return fromSpdlogLevel(detail::getLogger()->level()); } + +void setLogCallback(LogCallback callback) { + std::lock_guard lock(loggerMutex()); + auto &logger = loggerStorage(); + auto current_level = logger ? logger->level() : spdlog::level::info; + + if (logger) { + spdlog::drop(kLoggerName); + } + + if (callback) { + auto sink = std::make_shared( + [cb = std::move(callback)](const spdlog::details::log_msg &msg) { + cb(fromSpdlogLevel(msg.level), + std::string(msg.logger_name.data(), msg.logger_name.size()), + std::string(msg.payload.data(), msg.payload.size())); + }); + logger = std::make_shared(kLoggerName, sink); + } else { + logger = createDefaultLogger(); + } + + logger->set_level(current_level); + spdlog::register_logger(logger); +} + +} // namespace livekit diff --git a/src/room.cpp b/src/room.cpp index f2a7176d..7eed7ed9 100644 --- a/src/room.cpp +++ b/src/room.cpp @@ -31,12 +31,12 @@ #include "ffi.pb.h" #include "ffi_client.h" #include "livekit_ffi.h" +#include "lk_log.h" #include "room.pb.h" #include "room_proto_converter.h" #include "track.pb.h" #include "track_proto_converter.h" #include -#include namespace livekit { @@ -162,7 +162,7 @@ bool Room::Connect(const std::string &url, const std::string &token, // Setup e2eeManager std::unique_ptr new_e2ee_manager; if (options.encryption) { - std::cout << "creating E2eeManager " << std::endl; + LK_LOG_INFO("creating E2eeManager"); e2ee_manager_ = std::unique_ptr( new E2EEManager(room_handle_->get(), options.encryption.value())); } @@ -190,7 +190,7 @@ bool Room::Connect(const std::string &url, const std::string &token, } catch (const std::exception &e) { // On error, set the connection_state_ to Disconnected connection_state_ = ConnectionState::Disconnected; - std::cerr << "Room::Connect failed: " << e.what() << std::endl; + LK_LOG_ERROR("Room::Connect failed: {}", e.what()); return false; } } @@ -341,8 +341,8 @@ void Room::OnEvent(const FfiEvent &event) { // We saw a disconnect event for a participant we don't track // internally. This can happen on races or if we never created a // RemoteParticipant - std::cerr << "participant_disconnected for unknown identity: " - << identity << std::endl; + LK_LOG_WARN("participant_disconnected for unknown identity: {}", + identity); } } if (removed) { @@ -360,8 +360,7 @@ void Room::OnEvent(const FfiEvent &event) { { std::lock_guard guard(lock_); if (!local_participant_) { - std::cerr << "kLocalTrackPublished: local_participant_ is nullptr" - << std::endl; + LK_LOG_ERROR("kLocalTrackPublished: local_participant_ is nullptr"); break; } const auto <p = re.local_track_published(); @@ -369,8 +368,7 @@ void Room::OnEvent(const FfiEvent &event) { auto &pubs = local_participant_->trackPublications(); auto it = pubs.find(sid); if (it == pubs.end()) { - std::cerr << "local_track_published for unknown sid: " << sid - << std::endl; + LK_LOG_WARN("local_track_published for unknown sid: {}", sid); break; } ev.publication = it->second; @@ -386,8 +384,7 @@ void Room::OnEvent(const FfiEvent &event) { { std::lock_guard guard(lock_); if (!local_participant_) { - std::cerr << "kLocalTrackPublished: local_participant_ is nullptr" - << std::endl; + LK_LOG_ERROR("kLocalTrackUnpublished: local_participant_ is nullptr"); break; } const auto <u = re.local_track_unpublished(); @@ -395,8 +392,8 @@ void Room::OnEvent(const FfiEvent &event) { auto &pubs = local_participant_->trackPublications(); auto it = pubs.find(pub_sid); if (it == pubs.end()) { - std::cerr << "local_track_unpublished for unknown publication sid: " - << pub_sid << std::endl; + LK_LOG_WARN("local_track_unpublished for unknown publication sid: {}", + pub_sid); break; } ev.publication = it->second; @@ -418,8 +415,7 @@ void Room::OnEvent(const FfiEvent &event) { auto &pubs = local_participant_->trackPublications(); auto it = pubs.find(sid); if (it == pubs.end()) { - std::cerr << "local_track_subscribed for unknown sid: " << sid - << std::endl; + LK_LOG_WARN("local_track_subscribed for unknown sid: {}", sid); break; } auto publication = it->second; @@ -450,8 +446,7 @@ void Room::OnEvent(const FfiEvent &event) { ev.publication = rpublication; } else { // Optional: log if we get a track for an unknown participant - std::cerr << "track_published for unknown participant: " << identity - << std::endl; + LK_LOG_WARN("track_published for unknown participant: {}", identity); // Don't emit the break; } @@ -470,16 +465,17 @@ void Room::OnEvent(const FfiEvent &event) { const std::string &pub_sid = tu.publication_sid(); auto pit = remote_participants_.find(identity); if (pit == remote_participants_.end()) { - std::cerr << "track_unpublished for unknown participant: " << identity - << std::endl; + LK_LOG_WARN("track_unpublished for unknown participant: {}", + identity); break; } RemoteParticipant *rparticipant = pit->second.get(); auto &pubs = rparticipant->mutableTrackPublications(); auto it = pubs.find(pub_sid); if (it == pubs.end()) { - std::cerr << "track_unpublished for unknown publication sid " - << pub_sid << " (participant " << identity << ")\n"; + LK_LOG_WARN("track_unpublished for unknown publication sid {} " + "(participant {})", + pub_sid, identity); break; } ev.participant = rparticipant; @@ -505,8 +501,7 @@ void Room::OnEvent(const FfiEvent &event) { // Find participant auto pit = remote_participants_.find(identity); if (pit == remote_participants_.end()) { - std::cerr << "track_subscribed for unknown participant: " << identity - << "\n"; + LK_LOG_WARN("track_subscribed for unknown participant: {}", identity); break; } rparticipant = pit->second.get(); @@ -514,9 +509,9 @@ void Room::OnEvent(const FfiEvent &event) { auto &pubs = rparticipant->mutableTrackPublications(); auto pubIt = pubs.find(track_info.sid()); if (pubIt == pubs.end()) { - std::cerr << "track_subscribed for unknown publication sid " - << track_info.sid() << " (participant " << identity - << ")\n"; + LK_LOG_WARN("track_subscribed for unknown publication sid {} " + "(participant {})", + track_info.sid(), identity); break; } rpublication = pubIt->second; @@ -527,8 +522,8 @@ void Room::OnEvent(const FfiEvent &event) { } else if (track_info.kind() == proto::TrackKind::KIND_AUDIO) { remote_track = std::make_shared(owned_track); } else { - std::cerr << "track_subscribed with unsupported kind: " - << track_info.kind() << "\n"; + LK_LOG_WARN("track_subscribed with unsupported kind: {}", + static_cast(track_info.kind())); break; } // Attach to publication, mark subscribed @@ -555,16 +550,17 @@ void Room::OnEvent(const FfiEvent &event) { const std::string &track_sid = tu.track_sid(); auto pit = remote_participants_.find(identity); if (pit == remote_participants_.end()) { - std::cerr << "track_unsubscribed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN("track_unsubscribed for unknown participant: {}", + identity); break; } RemoteParticipant *rparticipant = pit->second.get(); auto &pubs = rparticipant->mutableTrackPublications(); auto pubIt = pubs.find(track_sid); if (pubIt == pubs.end()) { - std::cerr << "track_unsubscribed for unknown publication sid " - << track_sid << " (participant " << identity << ")\n"; + LK_LOG_WARN("track_unsubscribed for unknown publication sid {} " + "(participant {})", + track_sid, identity); break; } auto publication = pubIt->second; @@ -589,8 +585,8 @@ void Room::OnEvent(const FfiEvent &event) { const std::string &identity = tsf.participant_identity(); auto pit = remote_participants_.find(identity); if (pit == remote_participants_.end()) { - std::cerr << "track_subscription_failed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN("track_subscription_failed for unknown participant: {}", + identity); break; } ev.participant = pit->second.get(); @@ -620,14 +616,12 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "track_muted for unknown participant: " << identity - << "\n"; + LK_LOG_WARN("track_muted for unknown participant: {}", identity); break; } auto pub = participant->findTrackPublication(sid); if (!pub) { - std::cerr << "track_muted for unknown track sid: " << sid - << std::endl; + LK_LOG_WARN("track_muted for unknown track sid: {}", sid); } else { pub->setMuted(true); if (auto t = pub->track()) { @@ -661,15 +655,13 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "track_unmuted for unknown participant: " << identity - << "\n"; + LK_LOG_WARN("track_unmuted for unknown participant: {}", identity); break; } auto pub = participant->findTrackPublication(sid); if (!pub) { - std::cerr << "track_muted for unknown track sid: " << sid - << std::endl; + LK_LOG_WARN("track_unmuted for unknown track sid: {}", sid); } else { pub->setMuted(false); if (auto t = pub->track()) { @@ -757,8 +749,9 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "participant_metadata_changed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN( + "participant_metadata_changed for unknown participant: {}", + identity); break; } std::string old_metadata = participant->metadata(); @@ -789,8 +782,8 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "participant_name_changed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN("participant_name_changed for unknown participant: {}", + identity); break; } std::string old_name = participant->name(); @@ -820,9 +813,9 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr - << "participant_attributes_changed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN( + "participant_attributes_changed for unknown participant: {}", + identity); break; } // Build full attributes map @@ -859,9 +852,9 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "participant_encryption_status_changed for unknown " - "participant: " - << identity << "\n"; + LK_LOG_WARN("participant_encryption_status_changed for unknown " + "participant: {}", + identity); break; } ev.participant = participant; @@ -889,8 +882,8 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "connection_quality_changed for unknown participant: " - << identity << "\n"; + LK_LOG_WARN("connection_quality_changed for unknown participant: {}", + identity); break; } ev.participant = participant; @@ -934,7 +927,7 @@ void Room::OnEvent(const FfiEvent &event) { case proto::RoomEvent::kE2EeStateChanged: { E2eeStateChangedEvent ev; { - std::cerr << "e2ee_state_changed for participant: " << std::endl; + LK_LOG_DEBUG("e2ee_state_changed for participant"); std::lock_guard guard(lock_); const auto &es = re.e2ee_state_changed(); const std::string &identity = es.participant_identity(); @@ -948,8 +941,8 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "e2ee_state_changed for unknown participant: " - << identity << std::endl; + LK_LOG_WARN("e2ee_state_changed for unknown participant: {}", + identity); break; } @@ -974,8 +967,9 @@ void Room::OnEvent(const FfiEvent &event) { // TODO, maybe we should update our |connection_state_| // correspoindingly, but the this kConnectionStateChanged event is never // triggered in my local test. - std::cout << "cs.state() is " << cs.state() << " connection_state_ is " - << (int)connection_state_ << std::endl; + LK_LOG_DEBUG("cs.state() is {} connection_state_ is {}", + static_cast(cs.state()), + static_cast(connection_state_)); ev.state = static_cast(cs.state()); } if (delegate_snapshot) { @@ -1221,9 +1215,8 @@ void Room::OnEvent(const FfiEvent &event) { } } if (!participant) { - std::cerr << "Room::RoomEvent::kParticipantsUpdated participant " - "does not exist: " - << identity << std::endl; + LK_LOG_WARN("kParticipantsUpdated: participant does not exist: {}", + identity); continue; } diff --git a/src/tests/CMakeLists.txt b/src/tests/CMakeLists.txt index 2d9c46ab..af6aed18 100644 --- a/src/tests/CMakeLists.txt +++ b/src/tests/CMakeLists.txt @@ -41,6 +41,7 @@ if(INTEGRATION_TEST_SOURCES) target_link_libraries(livekit_integration_tests PRIVATE livekit + spdlog::spdlog GTest::gtest_main GTest::gmock ) @@ -51,10 +52,10 @@ if(INTEGRATION_TEST_SOURCES) ${LIVEKIT_ROOT_DIR}/src ) - # Define LIVEKIT_ROOT_DIR for tests to find data files target_compile_definitions(livekit_integration_tests PRIVATE LIVEKIT_ROOT_DIR="${LIVEKIT_ROOT_DIR}" + SPDLOG_ACTIVE_LEVEL=${_SPDLOG_ACTIVE_LEVEL} ) # Copy shared libraries to test executable directory diff --git a/src/tests/integration/test_logging.cpp b/src/tests/integration/test_logging.cpp new file mode 100644 index 00000000..00e4b963 --- /dev/null +++ b/src/tests/integration/test_logging.cpp @@ -0,0 +1,302 @@ +/* + * Copyright 2025 LiveKit + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include +#include + +#include "lk_log.h" + +#include +#include +#include +#include +#include + +namespace livekit { +namespace test { + +class LoggingTest : public ::testing::Test { +protected: + void SetUp() override { livekit::initialize(); } + + void TearDown() override { + livekit::setLogCallback(nullptr); + livekit::shutdown(); + } +}; + +// --------------------------------------------------------------------------- +// setLogLevel / getLogLevel round-trip +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, SetAndGetLogLevel) { + const LogLevel levels[] = { + LogLevel::Trace, LogLevel::Debug, LogLevel::Info, LogLevel::Warn, + LogLevel::Error, LogLevel::Critical, LogLevel::Off, + }; + + for (auto level : levels) { + livekit::setLogLevel(level); + EXPECT_EQ(livekit::getLogLevel(), level); + } +} + +TEST_F(LoggingTest, DefaultLogLevelIsInfo) { + EXPECT_EQ(livekit::getLogLevel(), LogLevel::Info); +} + +// --------------------------------------------------------------------------- +// setLogCallback captures messages +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, CallbackReceivesLogMessages) { + struct Captured { + LogLevel level; + std::string logger_name; + std::string message; + }; + + std::mutex mtx; + std::vector captured; + + livekit::setLogCallback( + [&](LogLevel level, const std::string &logger_name, + const std::string &message) { + std::lock_guard lock(mtx); + captured.push_back({level, logger_name, message}); + }); + + livekit::setLogLevel(LogLevel::Trace); + + LK_LOG_INFO("hello from test"); + + std::lock_guard lock(mtx); + ASSERT_GE(captured.size(), 1u); + + bool found = false; + for (const auto &entry : captured) { + if (entry.message.find("hello from test") != std::string::npos) { + EXPECT_EQ(entry.level, LogLevel::Info); + EXPECT_EQ(entry.logger_name, "livekit"); + found = true; + break; + } + } + EXPECT_TRUE(found) << "Expected callback to capture 'hello from test'"; +} + +TEST_F(LoggingTest, CallbackReceivesCorrectLevel) { + std::mutex mtx; + std::vector levels_seen; + + livekit::setLogCallback([&](LogLevel level, const std::string &, + const std::string &) { + std::lock_guard lock(mtx); + levels_seen.push_back(level); + }); + + livekit::setLogLevel(LogLevel::Trace); + + LK_LOG_WARN("a warning"); + LK_LOG_ERROR("an error"); + + std::lock_guard lock(mtx); + ASSERT_GE(levels_seen.size(), 2u); + + size_t n = levels_seen.size(); + EXPECT_EQ(levels_seen[n - 2], LogLevel::Warn); + EXPECT_EQ(levels_seen[n - 1], LogLevel::Error); +} + +// --------------------------------------------------------------------------- +// Level filtering via setLogLevel +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, MessagesFilteredBelowLevel) { + std::atomic call_count{0}; + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + call_count.fetch_add(1); + }); + + livekit::setLogLevel(LogLevel::Warn); + + LK_LOG_TRACE("should be filtered"); + LK_LOG_DEBUG("should be filtered"); + LK_LOG_INFO("should be filtered"); + + EXPECT_EQ(call_count.load(), 0) + << "Messages below Warn should not reach callback"; + + LK_LOG_WARN("should pass"); + LK_LOG_ERROR("should pass"); + LK_LOG_CRITICAL("should pass"); + + EXPECT_EQ(call_count.load(), 3) + << "Messages at or above Warn should reach callback"; +} + +TEST_F(LoggingTest, OffLevelSuppressesEverything) { + std::atomic call_count{0}; + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + call_count.fetch_add(1); + }); + + livekit::setLogLevel(LogLevel::Off); + + LK_LOG_TRACE("suppressed"); + LK_LOG_DEBUG("suppressed"); + LK_LOG_INFO("suppressed"); + LK_LOG_WARN("suppressed"); + LK_LOG_ERROR("suppressed"); + LK_LOG_CRITICAL("suppressed"); + + EXPECT_EQ(call_count.load(), 0); +} + +// --------------------------------------------------------------------------- +// setLogCallback(nullptr) restores default +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, NullCallbackRestoresDefault) { + std::atomic call_count{0}; + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + call_count.fetch_add(1); + }); + + livekit::setLogLevel(LogLevel::Trace); + LK_LOG_INFO("goes to callback"); + EXPECT_GE(call_count.load(), 1); + + int before = call_count.load(); + livekit::setLogCallback(nullptr); + + LK_LOG_INFO("goes to stderr, not callback"); + EXPECT_EQ(call_count.load(), before) + << "After setLogCallback(nullptr), old callback should not fire"; +} + +// --------------------------------------------------------------------------- +// Callback replacement +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, ReplacingCallbackStopsOldOne) { + std::atomic old_count{0}; + std::atomic new_count{0}; + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + old_count.fetch_add(1); + }); + + livekit::setLogLevel(LogLevel::Trace); + LK_LOG_INFO("to old"); + EXPECT_GE(old_count.load(), 1); + + int old_before = old_count.load(); + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + new_count.fetch_add(1); + }); + + LK_LOG_INFO("to new"); + + EXPECT_EQ(old_count.load(), old_before) + << "Old callback should not receive messages after replacement"; + EXPECT_GE(new_count.load(), 1) << "New callback should receive messages"; +} + +// --------------------------------------------------------------------------- +// Level is preserved across callback changes +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, LogLevelPreservedAcrossCallbackChange) { + livekit::setLogLevel(LogLevel::Error); + + livekit::setLogCallback( + [](LogLevel, const std::string &, const std::string &) {}); + + EXPECT_EQ(livekit::getLogLevel(), LogLevel::Error) + << "setLogCallback should preserve the current log level"; +} + +// --------------------------------------------------------------------------- +// Thread safety +// --------------------------------------------------------------------------- + +TEST_F(LoggingTest, ConcurrentSetLogLevelDoesNotCrash) { + constexpr int kThreads = 8; + constexpr int kIterations = 500; + + const LogLevel levels[] = {LogLevel::Trace, LogLevel::Debug, LogLevel::Info, + LogLevel::Warn, LogLevel::Error, LogLevel::Off}; + + std::vector threads; + threads.reserve(kThreads); + + for (int t = 0; t < kThreads; ++t) { + threads.emplace_back([&, t]() { + for (int i = 0; i < kIterations; ++i) { + livekit::setLogLevel(levels[(t + i) % 6]); + [[maybe_unused]] auto lvl = livekit::getLogLevel(); + } + }); + } + + for (auto &th : threads) { + th.join(); + } +} + +TEST_F(LoggingTest, ConcurrentLogEmissionDoesNotCrash) { + std::atomic call_count{0}; + + livekit::setLogCallback( + [&](LogLevel, const std::string &, const std::string &) { + call_count.fetch_add(1); + }); + + livekit::setLogLevel(LogLevel::Trace); + + constexpr int kThreads = 8; + constexpr int kIterations = 200; + + std::vector threads; + threads.reserve(kThreads); + + for (int t = 0; t < kThreads; ++t) { + threads.emplace_back([&, t]() { + for (int i = 0; i < kIterations; ++i) { + LK_LOG_INFO("thread {} iteration {}", t, i); + } + }); + } + + for (auto &th : threads) { + th.join(); + } + + EXPECT_GE(call_count.load(), kThreads * kIterations); +} + +} // namespace test +} // namespace livekit diff --git a/src/tests/integration/test_sdk_initialization.cpp b/src/tests/integration/test_sdk_initialization.cpp index 1c379af8..fde8ee1f 100644 --- a/src/tests/integration/test_sdk_initialization.cpp +++ b/src/tests/integration/test_sdk_initialization.cpp @@ -22,53 +22,47 @@ namespace test { class SDKInitializationTest : public ::testing::Test { protected: - void SetUp() override { - // Each test starts with a fresh SDK state - } + void SetUp() override {} - void TearDown() override { - // Ensure SDK is shutdown after each test - livekit::shutdown(); - } + void TearDown() override { livekit::shutdown(); } }; -TEST_F(SDKInitializationTest, InitializeWithConsoleLogging) { - bool result = livekit::initialize(livekit::LogSink::kConsole); +TEST_F(SDKInitializationTest, InitializeDefault) { + bool result = livekit::initialize(); EXPECT_TRUE(result) << "First initialization should succeed"; } -TEST_F(SDKInitializationTest, InitializeWithCallbackLogging) { - bool result = livekit::initialize(livekit::LogSink::kCallback); - EXPECT_TRUE(result) << "Initialization with callback logging should succeed"; +TEST_F(SDKInitializationTest, InitializeWithLogLevel) { + bool result = livekit::initialize(livekit::LogLevel::Debug); + EXPECT_TRUE(result) << "Initialization with explicit log level should succeed"; + EXPECT_EQ(livekit::getLogLevel(), livekit::LogLevel::Debug); } TEST_F(SDKInitializationTest, DoubleInitializationReturnsFalse) { - bool first = livekit::initialize(livekit::LogSink::kConsole); + bool first = livekit::initialize(); EXPECT_TRUE(first) << "First initialization should succeed"; - bool second = livekit::initialize(livekit::LogSink::kConsole); + bool second = livekit::initialize(); EXPECT_FALSE(second) << "Second initialization should return false"; } TEST_F(SDKInitializationTest, ReinitializeAfterShutdown) { - bool first = livekit::initialize(livekit::LogSink::kConsole); + bool first = livekit::initialize(); EXPECT_TRUE(first) << "First initialization should succeed"; livekit::shutdown(); - bool second = livekit::initialize(livekit::LogSink::kConsole); + bool second = livekit::initialize(); EXPECT_TRUE(second) << "Re-initialization after shutdown should succeed"; } TEST_F(SDKInitializationTest, ShutdownWithoutInitialize) { - // Should not crash EXPECT_NO_THROW(livekit::shutdown()); } TEST_F(SDKInitializationTest, MultipleShutdowns) { - livekit::initialize(livekit::LogSink::kConsole); + livekit::initialize(); - // Multiple shutdowns should not crash EXPECT_NO_THROW(livekit::shutdown()); EXPECT_NO_THROW(livekit::shutdown()); EXPECT_NO_THROW(livekit::shutdown()); diff --git a/src/video_frame.cpp b/src/video_frame.cpp index 5e1f230e..5fdc83e2 100644 --- a/src/video_frame.cpp +++ b/src/video_frame.cpp @@ -2,11 +2,11 @@ #include #include -#include #include #include #include "livekit/ffi_handle.h" +#include "lk_log.h" #include "video_utils.h" namespace livekit { @@ -79,8 +79,8 @@ std::vector computePlaneInfos(uintptr_t base, int width, int height, VideoBufferType type) { std::vector planes; if (!base || width <= 0 || height <= 0) { - std::cerr << "[VideoFrame] Warning: invalid planeInfos input (ptr=" - << base << ", w=" << width << ", h=" << height << ")\n"; + LK_LOG_WARN("VideoFrame: invalid planeInfos input (ptr={}, w={}, h={})", + base, width, height); return planes; } const auto w = static_cast(width); @@ -268,7 +268,7 @@ VideoFrame::VideoFrame() : width_{0}, height_{0}, type_{VideoBufferType::BGRA}, data_{} {} VideoFrame::VideoFrame(int width, int height, VideoBufferType type, - std::vector data) + std::vector data) : width_(width), height_(height), type_(type), data_(std::move(data)) { const std::size_t expected = computeBufferSize(width_, height_, type_); if (data_.size() < expected) { @@ -297,8 +297,7 @@ VideoFrame VideoFrame::convert(VideoBufferType dst, bool flip_y) const { // We still return a *new* VideoFrame, never `*this`, so copy-ctor // being deleted is not a problem. if (dst == type_ && !flip_y) { - std::cerr << "KVideoFrame::convert Warning: converting to the same format" - << std::endl; + LK_LOG_WARN("VideoFrame::convert: converting to the same format"); // copy pixel data std::vector buf = data_; return VideoFrame(width_, height_, type_, std::move(buf)); diff --git a/src/video_stream.cpp b/src/video_stream.cpp index ece6d35e..182617e3 100644 --- a/src/video_stream.cpp +++ b/src/video_stream.cpp @@ -5,6 +5,7 @@ #include "ffi.pb.h" #include "ffi_client.h" #include "livekit/track.h" +#include "lk_log.h" #include "video_frame.pb.h" #include "video_utils.h" @@ -130,8 +131,8 @@ void VideoStream::initFromTrack(const std::shared_ptr &track, auto resp = FfiClient::instance().sendRequest(req); if (!resp.has_new_video_stream()) { - std::cerr << "VideoStream::initFromTrack: FFI response missing " - "new_video_stream()\n"; + LK_LOG_ERROR( + "VideoStream::initFromTrack: FFI response missing new_video_stream()"); throw std::runtime_error("new_video_stream FFI request failed"); } // Adjust field names to match your proto exactly: diff --git a/src/video_utils.cpp b/src/video_utils.cpp index 19b32375..8b034de9 100644 --- a/src/video_utils.cpp +++ b/src/video_utils.cpp @@ -160,7 +160,7 @@ VideoFrame fromOwnedProto(const proto::OwnedVideoBuffer &owned) { } VideoFrame convertViaFfi(const VideoFrame &frame, VideoBufferType dst, - bool flip_y) { + bool flip_y) { proto::FfiRequest req; auto *vc = req.mutable_video_convert(); vc->set_flip_y(flip_y); diff --git a/src/video_utils.h b/src/video_utils.h index 8fc27dcd..69664154 100644 --- a/src/video_utils.h +++ b/src/video_utils.h @@ -25,7 +25,7 @@ namespace livekit { proto::VideoBufferInfo toProto(const VideoFrame &frame); VideoFrame fromOwnedProto(const proto::OwnedVideoBuffer &owned); VideoFrame convertViaFfi(const VideoFrame &frame, VideoBufferType dst, - bool flip_y); + bool flip_y); proto::VideoBufferType toProto(VideoBufferType t); VideoBufferType fromProto(proto::VideoBufferType t); diff --git a/vcpkg.json b/vcpkg.json index 2410ccb0..5161febe 100644 --- a/vcpkg.json +++ b/vcpkg.json @@ -11,7 +11,8 @@ "name": "protobuf", "version>=": "5.29.5" }, - "abseil" + "abseil", + "spdlog" ], "features": { "examples": { @@ -21,4 +22,4 @@ ] } } -} +} \ No newline at end of file