diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index c7a7bf7d5..9f20772b8 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -14,6 +14,7 @@ jobs: runs-on: ubuntu-latest container: ghcr.io/viamrobotics/cpp-base:bullseye-amd64 strategy: + fail-fast: false matrix: include: - BUILD_SHARED: ON diff --git a/CMakeLists.txt b/CMakeLists.txt index 86925b427..efb398aef 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -328,7 +328,18 @@ if (VIAMCPPSDK_BUILD_TESTS) set(VIAMCPPSDK_BOOST_TEST "unit_test_framework") endif() -find_package(Boost ${VIAMCPPSDK_BOOST_VERSION_MINIMUM} REQUIRED COMPONENTS headers log program_options ${VIAMCPPSDK_BOOST_TEST}) +if (VIAMCPPSDK_BUILD_EXAMPLES) + set(VIAMCPPSDK_BOOST_PROGRAM_OPTIONS "program_options") +endif() + +find_package(Boost ${VIAMCPPSDK_BOOST_VERSION_MINIMUM} REQUIRED + COMPONENTS + headers + log + log_setup + ${VIAMCPPSDK_BOOST_PROGRAM_OPTIONS} + ${VIAMCPPSDK_BOOST_TEST} +) # Time to find `protobuf` and `gRPC[++]`. Normally this would just be # something like `find_package(gRPC CONFIG REQUIRED)`, and diff --git a/etc/docker/tests/run_test.sh b/etc/docker/tests/run_test.sh index 6ac4702e8..f9418de3a 100755 --- a/etc/docker/tests/run_test.sh +++ b/etc/docker/tests/run_test.sh @@ -34,7 +34,7 @@ popd if [ ${BUILD_SHARED} = "ON" ] then pushd pkg-config - PKG_CONFIG_PATH=${INSTALL_DIR}/lib/pkgconfig make all + PKG_CONFIG_PATH=${INSTALL_DIR}/lib/pkgconfig CXXFLAGS="-DBOOST_LOG_DYN_LINK" make all run_module popd fi diff --git a/src/viam/config/viam-cpp-sdkConfig.cmake.in b/src/viam/config/viam-cpp-sdkConfig.cmake.in index 2ee214306..82dbf36fc 100644 --- a/src/viam/config/viam-cpp-sdkConfig.cmake.in +++ b/src/viam/config/viam-cpp-sdkConfig.cmake.in @@ -2,7 +2,7 @@ include(CMakeFindDependencyMacro) -find_dependency(Boost @Boost_VERSION_MAJOR@.@Boost_VERSION_MINOR@ COMPONENTS headers log) +find_dependency(Boost @Boost_VERSION_MAJOR@.@Boost_VERSION_MINOR@ COMPONENTS headers log log_setup) if (@gRPC_FOUND@) find_dependency(gRPC @gRPC_VERSION_MAJOR@.@gRPC_VERSION_MINOR@ CONFIG) diff --git a/src/viam/examples/camera/example_camera.cpp b/src/viam/examples/camera/example_camera.cpp index d1eb9b80c..5124f0ee9 100644 --- a/src/viam/examples/camera/example_camera.cpp +++ b/src/viam/examples/camera/example_camera.cpp @@ -5,97 +5,80 @@ #include #include +#include #include #include -int main() { - using std::cerr; - using std::cout; - using std::endl; +int main() try { namespace vs = ::viam::sdk; - try { - // Every Viam C++ SDK program must have one and only one Instance object which is created - // before - // any other C++ SDK objects and stays alive until all Viam C++ SDK objects are destroyed. - vs::Instance inst; - - // If you want to connect to a remote robot, this should be the url of the robot - // Ex: xxx.xxx.viam.cloud - std::string robot_address("localhost:8080"); - // If you want to connect to a remote robot, you need some authentication secret - // You can find this on app.viam.com - vs::Credentials credentials("", ""); - - vs::DialOptions dial_options; - - // If you have credentials, use this to pass them to the robot - // dial_options.credentials = credentials; - - // This is for an example. Care should be taken before exercising this option in production. - dial_options.set_allow_insecure_downgrade( - (credentials.type().empty() && credentials.payload().empty())); - - // Set the refresh interval of the robot (in seconds) (0 = auto refresh) and the dial - // options - vs::Options options = vs::Options(1, dial_options); - - std::shared_ptr robot; - try { - robot = vs::RobotClient::at_address(robot_address, options); - cout << "Successfully connected to the robot" << endl; - } catch (const std::exception& e) { - cerr << "Failed to connect to the robot. Exiting." << endl; - throw; - } - - std::vector resource_names = robot->resource_names(); - - cout << "Resources of the robot:" << endl; - for (const auto& resource : resource_names) { - cout << " - " << resource.name() << " (" << resource.api().resource_subtype() << ")" - << endl; - } - - std::string camera_name("camera1"); - - cout << "Getting camera: " << camera_name << endl; - std::shared_ptr camera; - try { - camera = robot->resource_by_name(camera_name); - } catch (const std::exception& e) { - cerr << "Failed to find " << camera_name << ". Exiting." << endl; - throw; - } - vs::Camera::properties props = camera->get_properties(); - vs::Camera::intrinsic_parameters intrinsics = props.intrinsic_parameters; - cout << "Image dimensions: " << intrinsics.width_px << " x " << intrinsics.height_px - << endl; - - std::string output_file("img.png"); - std::string image_mime_type("image/png"); - - cout << "Getting image from camera " << endl; - vs::Camera::raw_image img = camera->get_image(image_mime_type); - cout << "Got image of mime type: " << img.mime_type << endl; - - cout << "Getting and saving image to " << output_file << endl; - std::ofstream fout; - fout.open(output_file, std::ios::binary | std::ios::out); - if (fout.fail()) { - throw std::runtime_error("Failed to open output file " + output_file); - } - fout.write(reinterpret_cast(img.bytes.data()), img.bytes.size()); - fout.close(); - if (fout.fail()) { - throw std::runtime_error("Failed to write and close output file " + output_file); - } - } catch (const std::exception& ex) { - cerr << "Program failed. Exception: " << std::string(ex.what()) << endl; - return EXIT_FAILURE; - } catch (...) { - cerr << "Program failed without exception message." << endl; - return EXIT_FAILURE; + // Every Viam C++ SDK program must have one and only one Instance object which is created + // before + // any other C++ SDK objects and stays alive until all Viam C++ SDK objects are destroyed. + vs::Instance inst; + + // If you want to connect to a remote robot, this should be the url of the robot + // Ex: xxx.xxx.viam.cloud + std::string robot_address("localhost:8080"); + // If you want to connect to a remote robot, you need some authentication secret + // You can find this on app.viam.com + vs::Credentials credentials("", ""); + + vs::DialOptions dial_options; + + // If you have credentials, use this to pass them to the robot + // dial_options.credentials = credentials; + + // This is for an example. Care should be taken before exercising this option in production. + dial_options.set_allow_insecure_downgrade( + (credentials.type().empty() && credentials.payload().empty())); + + // Set the refresh interval of the robot (in seconds) (0 = auto refresh) and the dial + // options + vs::Options options = vs::Options(1, dial_options); + + std::shared_ptr robot = vs::RobotClient::at_address(robot_address, options); + VIAM_SDK_LOG(info) << "Successfully connected to the robot"; + + std::vector resource_names = robot->resource_names(); + + VIAM_SDK_LOG(info) << "Resources of the robot:"; + for (const auto& resource : resource_names) { + VIAM_SDK_LOG(info) << " - " << resource.name() << " (" << resource.api().resource_subtype() + << ")"; } + std::string camera_name("camera1"); + + VIAM_SDK_LOG(info) << "Getting camera: " << camera_name; + std::shared_ptr camera = robot->resource_by_name(camera_name); + + vs::Camera::properties props = camera->get_properties(); + vs::Camera::intrinsic_parameters intrinsics = props.intrinsic_parameters; + VIAM_SDK_LOG(info) << "Image dimensions: " << intrinsics.width_px << " x " + << intrinsics.height_px; + + std::string output_file("img.png"); + std::string image_mime_type("image/png"); + + VIAM_SDK_LOG(info) << "Getting image from camera "; + + vs::Camera::raw_image img = camera->get_image(image_mime_type); + + VIAM_SDK_LOG(info) << "Got image of mime type: " << img.mime_type; + + VIAM_SDK_LOG(info) << "Getting and saving image to " << output_file; + + std::ofstream fout; + + // Operations on the ofstream will throw on failure. + fout.exceptions(std::ofstream::failbit); + fout.open(output_file, std::ios::binary | std::ios::out); + + fout.write(reinterpret_cast(img.bytes.data()), img.bytes.size()); + fout.close(); + return EXIT_SUCCESS; +} catch (const std::exception& ex) { + std::cerr << "Program failed. Exception: " << std::string(ex.what()) << "\n"; + return EXIT_FAILURE; } diff --git a/src/viam/examples/dial/example_dial.cpp b/src/viam/examples/dial/example_dial.cpp index f39522c26..60c052fe1 100644 --- a/src/viam/examples/dial/example_dial.cpp +++ b/src/viam/examples/dial/example_dial.cpp @@ -11,6 +11,7 @@ #include #include +#include #include #include @@ -36,15 +37,15 @@ int main() { // ensure we can query resources std::vector resource_names = robot->resource_names(); - std::cout << "Resources" << std::endl; + VIAM_SDK_LOG(info) << "Resources:"; for (const Name& resource : resource_names) { - std::cout << "\t" << resource << "\n"; + VIAM_SDK_LOG(info) << resource; } // ensure we can create clients to the robot auto gc = robot->resource_by_name("generic1"); if (gc) { - std::cout << "got generic component client named " << gc->name() << std::endl; + VIAM_SDK_LOG(info) << "got generic component client named " << gc->name(); } return EXIT_SUCCESS; diff --git a/src/viam/examples/dial_api_key/example_dial_api_key.cpp b/src/viam/examples/dial_api_key/example_dial_api_key.cpp index b723e4227..850fe0dc9 100644 --- a/src/viam/examples/dial_api_key/example_dial_api_key.cpp +++ b/src/viam/examples/dial_api_key/example_dial_api_key.cpp @@ -50,9 +50,9 @@ int main(int argc, char* argv[]) { // ensure we can query resources std::vector resource_names = robot->resource_names(); - std::cout << "Resources" << std::endl; + VIAM_SDK_LOG(info) << "Resources:"; for (const Name& resource : resource_names) { - std::cout << "\t" << resource << "\n"; + VIAM_SDK_LOG(info) << resource; } return EXIT_SUCCESS; diff --git a/src/viam/examples/mlmodel/example_audio_classification_client.cpp b/src/viam/examples/mlmodel/example_audio_classification_client.cpp index 6be570449..51e5731ea 100644 --- a/src/viam/examples/mlmodel/example_audio_classification_client.cpp +++ b/src/viam/examples/mlmodel/example_audio_classification_client.cpp @@ -83,6 +83,18 @@ int main(int argc, char* argv[]) try { // any other C++ SDK objects and stays alive until all Viam C++ SDK objects are destroyed. viam::sdk::Instance inst; + // By default, log messages with VIAM_SDK_LOG have "Viam C++ SDK" as the resource name. + // Here we override it with the name of the executable, trimming the leading path if present. + + std::string exe_name{argv[0]}; + + const auto last_slash_pos = exe_name.find_last_of('/'); + if (last_slash_pos != std::string::npos) { + exe_name = exe_name.substr(last_slash_pos); + } + + viam::sdk::LogManager::get().set_global_resource_name(exe_name); + // Build up our command line options. The example operates in two // modes. In the "--generate" mode, it takes command line // parameters needed to satisfy the interpolation points in the @@ -168,35 +180,33 @@ int main(int argc, char* argv[]) try { if (opt_generating) { // Validate that we have the right options for generation. if (opt_robot_host || opt_api_key || opt_api_key_id) { - std::cout << argv[0] - << ": With `--generate`, do not provide `--robot-{host,api-key,api-key-id}`" - << std::endl; + VIAM_SDK_LOG(error) + << "With `--generate`, do not provide `--robot-{host,api-key,api-key-id}`"; return EXIT_FAILURE; } if (!opt_model_path) { - std::cout << argv[0] << ": With `--generate`, a `--model-path` is required" - << std::endl; + VIAM_SDK_LOG(error) << "With `--generate`, a `--model-path` is required"; return EXIT_FAILURE; } + const bf::path model_path(opt_model_path.get()); if (!bf::is_regular_file(model_path)) { - std::cout << argv[0] << ": The path `" << model_path.c_str() - << "` provided for `--model-path` is not an existing regular file" - << std::endl; + VIAM_SDK_LOG(error) << "The path `" << model_path.c_str() + << "` provided for `--model-path` is not an existing regular file"; return EXIT_FAILURE; } if (!opt_tflite_module_path) { - std::cout << argv[0] << ": With `--generate`, a `--tflite-module-path` is required" - << std::endl; + VIAM_SDK_LOG(error) << "With `--generate`, a `--tflite-module-path` is required"; return EXIT_FAILURE; } + const bf::path tflite_module_path(opt_tflite_module_path.get()); if (!bf::is_regular_file(tflite_module_path)) { - std::cout << argv[0] << ": The path `" << tflite_module_path.c_str() - << "` provided for `--tflite-module-path` is not an existing regular file" - << std::endl; + VIAM_SDK_LOG(error) + << "The path `" << tflite_module_path.c_str() + << "` provided for `--tflite-module-path` is not an existing regular file"; return EXIT_FAILURE; } @@ -207,28 +217,25 @@ int main(int argc, char* argv[]) try { const auto config = boost::format(kRobotConfigTemplate) % bf::absolute(model_path).c_str() % bf::absolute(tflite_module_path).c_str(); - std::cout << config << std::endl; + VIAM_SDK_LOG(info) << config << std::endl; } else { // Validate that we have the right options for classification mode. if (opt_model_path || opt_tflite_module_path) { - std::cout << argv[0] << ": Without `--generate`, do not provide `--*path*` arguments" - << std::endl; + VIAM_SDK_LOG(error) << "Without `--generate`, do not provide `--*path*` arguments"; return EXIT_FAILURE; } if (!opt_robot_host) { - std::cout << argv[0] - << ": The `--robot-host` argument is required when connecting to a robot" - << std::endl; + VIAM_SDK_LOG(error) + << "The `--robot-host` argument is required when connecting to a robot"; return EXIT_FAILURE; } if (!opt_api_key || !opt_api_key_id) { - std::cout << argv[0] - << ": The `--robot-api-key` and the `--robot-api-key-id` argument are " - "required when connecting to a robot" - << std::endl; + VIAM_SDK_LOG(error) + << "The `--robot-api-key` and the `--robot-api-key-id` argument are " + "required when connecting to a robot"; return EXIT_FAILURE; } @@ -248,10 +255,9 @@ int main(int argc, char* argv[]) try { auto yamnet_service = robot->resource_by_name("yamnet_classification_tflite"); if (!yamnet_service) { - std::cout << argv[0] << ": " - << "Failed: did not find the `yamnet_classification_tflite` resource, cannot " - "continue" - << std::endl; + VIAM_SDK_LOG(error) + << " did not find the `yamnet_classification_tflite` resource, cannot " + "continue"; return EXIT_FAILURE; } @@ -296,8 +302,7 @@ int main(int argc, char* argv[]) try { // the robot configuration. auto categories = result->find("categories"); if (categories == result->end()) { - std::cout << argv[0] << ": " - << "Failed: a `categories` tensor was not returned" << std::endl; + VIAM_SDK_LOG(error) << "A `categories` tensor was not returned"; return EXIT_FAILURE; } @@ -311,10 +316,8 @@ int main(int argc, char* argv[]) try { const auto* const categories_float = boost::get>(&categories->second); if (!categories_float) { - std::cout - << argv[0] << ": " - << "Failed: a `categories` tensor was returned, but it was not of type `float`" - << std::endl; + VIAM_SDK_LOG(error) + << "A `categories` tensor was returned, but it was not of type `float`"; return EXIT_FAILURE; } @@ -323,23 +326,23 @@ int main(int argc, char* argv[]) try { // results and print out the label and score. if (!opt_model_label_path) { for (const auto& val : *categories_float) { - std::cout << val << std::endl; + VIAM_SDK_LOG(info) << val; } } else { // Ensure that the label path is something we can actually read from. const bf::path model_label_path(opt_model_label_path.get()); if (!bf::is_regular_file(model_label_path)) { - std::cout << argv[0] << ": Failed: The path `" << model_label_path.c_str() - << "` provided for `--model-label-path` is not an existing regular file" - << std::endl; + VIAM_SDK_LOG(error) + << "The path `" << model_label_path.c_str() + << "` provided for `--model-label-path` is not an existing regular file"; return EXIT_FAILURE; } // Open the labels file, or bail. std::ifstream labels_stream(model_label_path.c_str()); if (!labels_stream) { - std::cout << argv[0] << ": Failed: Unable to open label path `" - << model_label_path.c_str() << "`" << std::endl; + VIAM_SDK_LOG(error) + << "Unable to open label path `" << model_label_path.c_str() << "`"; return EXIT_FAILURE; } @@ -353,9 +356,8 @@ int main(int argc, char* argv[]) try { // If the tensor size doesn't match the labels file size, then the labels file // is probably incorrect. if (categories_float->size() != labels.size()) { - std::cout << argv[0] - << ": Failed: Size mismatch between category scores and label files" - << std::endl; + VIAM_SDK_LOG(error) + << "Size mismatch between category scores and label files" << std::endl; return EXIT_FAILURE; } @@ -364,10 +366,12 @@ int main(int argc, char* argv[]) try { const std::string* label; float score; }; + std::vector scored_labels; for (size_t i = 0; i != labels.size(); ++i) { scored_labels.push_back({&labels[i], (*categories_float)[i]}); } + std::sort(begin(scored_labels), end(scored_labels), [](const auto& l, const auto& r) { return l.score > r.score; }); @@ -375,40 +379,36 @@ int main(int argc, char* argv[]) try { // Print out the top 5 (or fewer) label/score pairs. for (size_t i = 0; i != std::min(5UL, scored_labels.size()); ++i) { // TODO: Avoid hardcoding the width here. - std::cout << boost::format("%1%: %2% %|40t|%3%\n") % i % *scored_labels[i].label % - scored_labels[i].score; + VIAM_SDK_LOG(info) << boost::format("%1%: %2% %|40t|%3%\n") % i % + *scored_labels[i].label % scored_labels[i].score; } - std::cout.flush(); } // Run 100 rounds of inference, accumulate some descriptive // statistics, and report them. - std::cout << "\nMeasuring inference latency ...\n"; + VIAM_SDK_LOG(info) << "\nMeasuring inference latency ..."; bacc::accumulator_set>> accumulator; + for (std::size_t i = 0; i != 100; ++i) { const auto start = std::chrono::steady_clock::now(); static_cast(yamnet_service->infer(inputs)); const auto finish = std::chrono::steady_clock::now(); const std::chrono::duration elapsed = finish - start; - ; accumulator(elapsed.count()); } - std::cout << "Inference latency (seconds), Mean: " << bacc::mean(accumulator) << std::endl; - std::cout << "Inference latency (seconds), Var : " << bacc::moment<2>(accumulator) - << std::endl; + + VIAM_SDK_LOG(info) << "Inference latency (seconds), Mean: " << bacc::mean(accumulator); + VIAM_SDK_LOG(info) << "Inference latency (seconds), Var : " << bacc::moment<2>(accumulator); return EXIT_SUCCESS; } } catch (const std::exception& ex) { - std::cout << argv[0] << ": " - << "Failed: a std::exception was thrown: `" << ex.what() << "``" << std::endl; + std::cerr << argv[0] << ": " + << "Failed: a std::exception was thrown: `" << ex.what() << "``\n"; return EXIT_FAILURE; -} catch (const std::string& ex) { - std::cout << argv[0] << ": " - << "Failed: a std::string was thrown: `" << ex << "``" << std::endl; } catch (...) { - std::cout << argv[0] << ": " - << "Failed: an unknown exception was thrown" << std::endl; + std::cerr << argv[0] << ": " + << "Failed: an unknown exception was thrown\n"; return EXIT_FAILURE; } diff --git a/src/viam/examples/modules/complex/base/impl.cpp b/src/viam/examples/modules/complex/base/impl.cpp index 14ed4bb4d..0672076a7 100644 --- a/src/viam/examples/modules/complex/base/impl.cpp +++ b/src/viam/examples/modules/complex/base/impl.cpp @@ -2,7 +2,6 @@ #include #include -#include #include #include @@ -10,6 +9,7 @@ #include #include #include +#include #include using namespace viam::sdk; @@ -106,7 +106,8 @@ void MyBase::set_power(const Vector3& linear, const Vector3& angular, const Prot } ProtoStruct MyBase::do_command(const ProtoStruct& command) { - std::cout << "Received DoCommand request for MyBase " << Resource::name() << std::endl; + // The VIAM_RESOURCE_LOG macro will associate log messages to the current resource + VIAM_RESOURCE_LOG(info) << "Received DoCommand request"; return command; } diff --git a/src/viam/examples/modules/complex/client.cpp b/src/viam/examples/modules/complex/client.cpp index 4c26f055f..28bd451dc 100644 --- a/src/viam/examples/modules/complex/client.cpp +++ b/src/viam/examples/modules/complex/client.cpp @@ -13,6 +13,7 @@ #include #include +#include #include #include @@ -48,54 +49,61 @@ int main() { // Connect to robot. std::shared_ptr robot = RobotClient::at_address(address, options); // Print resources. - std::cout << "Resources" << std::endl; + VIAM_SDK_LOG(info) << "Resources:"; std::vector resource_names = robot->resource_names(); for (const Name& resource : resource_names) { - std::cout << "\t" << resource << "\n"; + VIAM_SDK_LOG(info) << resource; } // Exercise Gizmo methods. auto gc = robot->resource_by_name("gizmo1"); if (!gc) { - std::cerr << "could not get 'gizmo1' resource from robot" << std::endl; + VIAM_SDK_LOG(error) << "could not get 'gizmo1' resource from robot" << std::endl; return EXIT_FAILURE; } + bool do_one_ret = gc->do_one("arg1"); - std::cout << "gizmo1 do_one returned: " << do_one_ret << std::endl; + VIAM_SDK_LOG(info) << "gizmo1 do_one returned: " << do_one_ret; + bool do_one_client_stream_ret = gc->do_one_client_stream({"arg1", "arg1", "arg1"}); - std::cout << "gizmo1 do_one_client_stream returned: " << do_one_client_stream_ret << std::endl; + VIAM_SDK_LOG(info) << "gizmo1 do_one_client_stream returned: " << do_one_client_stream_ret; + std::string do_two_ret = gc->do_two(false); - std::cout << "gizmo1 do_two returned: " << do_two_ret << std::endl; + VIAM_SDK_LOG(info) << "gizmo1 do_two returned: " << do_two_ret; + std::vector do_one_server_stream_ret = gc->do_one_server_stream("arg1"); - std::cout << "gizmo1 do_one_server_stream returned: " << std::endl; + VIAM_SDK_LOG(info) << "gizmo1 do_one_server_stream returned: "; for (bool ret : do_one_server_stream_ret) { - std::cout << '\t' << ret << std::endl; + VIAM_SDK_LOG(info) << ret; } + std::vector do_one_bidi_stream_ret = gc->do_one_bidi_stream({"arg1", "arg2", "arg3"}); - std::cout << "gizmo1 do_one_bidi_stream returned: " << std::endl; + VIAM_SDK_LOG(info) << "gizmo1 do_one_bidi_stream returned: "; for (bool ret : do_one_bidi_stream_ret) { - std::cout << '\t' << ret << std::endl; + VIAM_SDK_LOG(info) << ret; } // Exercise Summation methods. auto sc = robot->resource_by_name("mysum1"); if (!sc) { - std::cerr << "could not get 'mysum1' resource from robot" << std::endl; + VIAM_SDK_LOG(error) << "could not get 'mysum1' resource from robot"; return EXIT_FAILURE; } + double sum = sc->sum({0, 1, 2, 3, 4, 5, 6, 7, 8, 9}); - std::cout << "mysum1 sum of numbers [0, 10) is: " << sum << std::endl; + VIAM_SDK_LOG(info) << "mysum1 sum of numbers [0, 10) is: " << sum; // Exercise a Base method. auto mc = robot->resource_by_name("motor1"); if (!mc) { - std::cerr << "could not get 'motor1' resource from robot" << std::endl; + VIAM_SDK_LOG(error) << "could not get 'motor1' resource from robot"; return EXIT_FAILURE; } + if (mc->is_moving()) { - std::cout << "motor1 is moving" << std::endl; + VIAM_SDK_LOG(info) << "motor1 is moving"; } else { - std::cout << "motor1 is not moving" << std::endl; + VIAM_SDK_LOG(info) << "motor1 is not moving"; } return EXIT_SUCCESS; diff --git a/src/viam/examples/modules/complex/gizmo/impl.cpp b/src/viam/examples/modules/complex/gizmo/impl.cpp index adbf8675a..93a21fb18 100644 --- a/src/viam/examples/modules/complex/gizmo/impl.cpp +++ b/src/viam/examples/modules/complex/gizmo/impl.cpp @@ -1,7 +1,6 @@ #include "impl.hpp" #include -#include #include #include diff --git a/src/viam/examples/modules/complex/main.cpp b/src/viam/examples/modules/complex/main.cpp index 253e69d78..91dbe3a2c 100644 --- a/src/viam/examples/modules/complex/main.cpp +++ b/src/viam/examples/modules/complex/main.cpp @@ -1,7 +1,6 @@ #include #include -#include #include #include @@ -9,6 +8,7 @@ #include #include #include +#include #include #include #include @@ -48,6 +48,9 @@ int main(int argc, char** argv) { [](Dependencies deps, ResourceConfig cfg) { return std::make_unique(deps, cfg); }, MyGizmo::validate); + // Write general log statements with the VIAM_SDK_LOG macro + VIAM_SDK_LOG(info) << "Registered mybase and mygizmo"; + Model mysummation_model("viam", "summation", "mysummation"); std::shared_ptr mysummation_mr = std::make_shared( diff --git a/src/viam/examples/modules/simple/client.cpp b/src/viam/examples/modules/simple/client.cpp index f08410336..75ca90e34 100644 --- a/src/viam/examples/modules/simple/client.cpp +++ b/src/viam/examples/modules/simple/client.cpp @@ -5,6 +5,7 @@ #include #include #include +#include #include #include @@ -32,16 +33,16 @@ int main() { std::shared_ptr robot = RobotClient::at_address(address, options); // Print resources - std::cout << "Resources\n"; + VIAM_SDK_LOG(info) << "Resources"; std::vector resource_names = robot->resource_names(); for (const Name& resource : resource_names) { - std::cout << "\t" << resource << "\n"; + VIAM_SDK_LOG(info) << resource; } // Exercise sensor methods auto sensor = robot->resource_by_name("mysensor"); if (!sensor) { - std::cerr << "could not get 'mysensor' resource from robot\n"; + VIAM_SDK_LOG(error) << "could not get 'mysensor' resource from robot"; return EXIT_FAILURE; } @@ -49,7 +50,7 @@ int main() { ProtoStruct resp = sensor->do_command(command); if (command != resp) { - std::cerr << "Got unexpected result from 'mysensor'\n"; + VIAM_SDK_LOG(error) << "Got unexpected result from 'mysensor'"; return EXIT_FAILURE; } @@ -57,15 +58,15 @@ int main() { auto itr = readings.find("signal"); if (itr == readings.end()) { - std::cerr << "Expected signal not found in sensor readings\n"; + VIAM_SDK_LOG(error) << "Expected signal not found in sensor readings"; return EXIT_FAILURE; } const double* signal = itr->second.get(); if (signal) { - std::cout << "\t" << itr->first << ": " << *signal << "\n"; + VIAM_SDK_LOG(info) << itr->first << ": " << *signal; } else { - std::cerr << "Unexpected value type for sensor reading\n"; + VIAM_SDK_LOG(error) << "Unexpected value type for sensor reading"; return EXIT_FAILURE; } diff --git a/src/viam/examples/modules/simple/main.cpp b/src/viam/examples/modules/simple/main.cpp index e85c2fe3a..10f791d76 100644 --- a/src/viam/examples/modules/simple/main.cpp +++ b/src/viam/examples/modules/simple/main.cpp @@ -7,6 +7,7 @@ #include #include #include +#include #include #include #include @@ -65,7 +66,9 @@ void MySensor::reconfigure(const Dependencies&, const ResourceConfig& cfg) { ProtoStruct MySensor::do_command(const ProtoStruct& command) { for (const auto& entry : command) { - std::cout << "Command entry " << entry.first; + // The VIAM_RESOURCE_LOG macro will associate log messages to the current resource and can + // be filtered upon + VIAM_RESOURCE_LOG(info) << "Command entry " << entry.first; } return command; @@ -80,6 +83,9 @@ int main(int argc, char** argv) try { // any other C++ SDK objects and stays alive until all Viam C++ SDK objects are destroyed. Instance inst; + // Write general log statements with the VIAM_SDK_LOG macro + VIAM_SDK_LOG(info) << "Starting up simple sensor module"; + Model mysensor_model("viam", "sensor", "mysensor"); std::shared_ptr mr = std::make_shared( diff --git a/src/viam/examples/modules/tflite/main.cpp b/src/viam/examples/modules/tflite/main.cpp index 65ca8c191..4bebd97d2 100644 --- a/src/viam/examples/modules/tflite/main.cpp +++ b/src/viam/examples/modules/tflite/main.cpp @@ -757,10 +757,10 @@ int serve(const std::string& socket_path) try { return EXIT_SUCCESS; } catch (const std::exception& ex) { - std::cout << "ERROR: A std::exception was thrown from `serve`: " << ex.what() << std::endl; + std::cerr << "ERROR: A std::exception was thrown from `serve`: " << ex.what() << std::endl; return EXIT_FAILURE; } catch (...) { - std::cout << "ERROR: An unknown exception was thrown from `serve`" << std::endl; + std::cerr << "ERROR: An unknown exception was thrown from `serve`" << std::endl; return EXIT_FAILURE; } @@ -770,8 +770,8 @@ int main(int argc, char* argv[]) { const std::string usage = "usage: mlmodelservice_tflite /path/to/unix/socket"; if (argc < 2) { - std::cout << "ERROR: insufficient arguments\n"; - std::cout << usage << "\n"; + std::cerr << "ERROR: insufficient arguments\n"; + std::cerr << usage << "\n"; return EXIT_FAILURE; } diff --git a/src/viam/examples/motor/example_motor.cpp b/src/viam/examples/motor/example_motor.cpp index 3d5a640ef..4cc781f0f 100644 --- a/src/viam/examples/motor/example_motor.cpp +++ b/src/viam/examples/motor/example_motor.cpp @@ -8,6 +8,7 @@ #include #include +#include #include #include @@ -15,116 +16,99 @@ void print_motor_position(std::shared_ptr motor) { // Whether the motor supports returning its position if (motor->get_properties().position_reporting) { // Position is measured in rotations (position is a typedef double) - std::cout << "Motor pos: " << motor->get_position() << std::endl; + VIAM_SDK_LOG(info) << "Motor pos: " << motor->get_position(); } else { - std::cout << "Motor position unavailable" << std::endl; + VIAM_SDK_LOG(info) << "Motor position unavailable"; } } -int main() { - using std::cerr; - using std::cout; - using std::endl; +int main() try { namespace vs = ::viam::sdk; - try { - // Every Viam C++ SDK program must have one and only one Instance object which is created - // before any other C++ SDK objects and stays alive until all Viam C++ SDK objects are - // destroyed. - vs::Instance inst; - - // If you want to connect to a remote robot, this should be the url of the robot - // Ex: xxx.xxx.viam.cloud - std::string robot_address("localhost:8080"); - // If you want to connect to a remote robot, you need some authentication secret - // You can find this on app.viam.com - vs::Credentials credentials("", ""); - - vs::DialOptions dial_options; - - // If you have credentials, use this to pass them to the robot - // dial_options.credentials = credentials; - - // This is for an example. Care should be taken before exercising this option in production. - dial_options.set_allow_insecure_downgrade( - (credentials.type().empty() && credentials.payload().empty())); - - // Set the refresh interval of the robot (in seconds) (0 = auto refresh) and the dial - // options - vs::Options options = vs::Options(1, dial_options); - - std::shared_ptr robot; - try { - robot = vs::RobotClient::at_address(robot_address, options); - cout << "Successfully connected to the robot" << endl; - } catch (const std::exception& e) { - cerr << "Failed to connect to the robot. Exiting." << endl; - throw; - } - - std::vector resource_names = robot->resource_names(); - - cout << "Resources of the robot:" << endl; - for (const vs::Name& resource : resource_names) { - cout << resource << endl; - } - - std::string motor_name("motor1"); - - cout << "Getting motor: " << motor_name << endl; - std::shared_ptr motor; - try { - motor = robot->resource_by_name(motor_name); - } catch (const std::exception& e) { - cerr << "Failed to find " << motor_name << ". Exiting." << endl; - throw; - } - - // Motors are always turned off if there is no attached client so this is expected to be 0 - cout << "Motor power: " << motor->get_power_status().power_pct << endl; - cout << "Setting motor power to 50%" << endl; - motor->set_power(0.5); - cout << "Motor power: " << motor->get_power_status().power_pct << endl; + // Every Viam C++ SDK program must have one and only one Instance object which is created + // before any other C++ SDK objects and stays alive until all Viam C++ SDK objects are + // destroyed. + vs::Instance inst; - print_motor_position(motor); + // If you want to connect to a remote robot, this should be the url of the robot + // Ex: xxx.xxx.viam.cloud + std::string robot_address("localhost:8080"); + // If you want to connect to a remote robot, you need some authentication secret + // You can find this on app.viam.com + vs::Credentials credentials("", ""); - cout << "Moving motor by 0.5 rotations at 10rpm" << endl; - motor->go_for(10, 0.5); - print_motor_position(motor); - cout << "Moving motor back to starting location" << endl; - if (motor->get_properties().position_reporting) { - // More accurate - motor->go_to(10, 0); - } else { - // If position reporting is unavailable, we cannot call go_to - // but we can defer to reverting past actions - motor->go_for(10, -0.5); - } - print_motor_position(motor); - cout << "Moving motor forward for 2 seconds at 30rpm" << endl; - // With `revolutions`==0, the call will be non-blocking - // and the motor will rotate indefintely. - motor->go_for(30, 0); + vs::DialOptions dial_options; - print_motor_position(motor); + // If you have credentials, use this to pass them to the robot + // dial_options.credentials = credentials; + + // This is for an example. Care should be taken before exercising this option in production. + dial_options.set_allow_insecure_downgrade( + (credentials.type().empty() && credentials.payload().empty())); + + // Set the refresh interval of the robot (in seconds) (0 = auto refresh) and the dial + // options + vs::Options options = vs::Options(1, dial_options); + + std::shared_ptr robot = vs::RobotClient::at_address(robot_address, options); + VIAM_SDK_LOG(info) << "Successfully connected to the robot"; - // Wait for 2 seconds, print position every 0.5 seconds - for (int i = 0; i < 4; i++) { - std::this_thread::sleep_for(std::chrono::milliseconds(500)); - print_motor_position(motor); - } - - // Explicitly stop the motor - cout << "Stopping motor" << endl; - motor->stop({}); - - } catch (const std::exception& ex) { - cerr << "Program failed. Exception: " << std::string(ex.what()) << endl; - return EXIT_FAILURE; - } catch (...) { - cerr << "Program failed without exception message." << endl; - return EXIT_FAILURE; + std::vector resource_names = robot->resource_names(); + + VIAM_SDK_LOG(info) << "Resources of the robot:"; + for (const vs::Name& resource : resource_names) { + VIAM_SDK_LOG(info) << resource; } + std::string motor_name("motor1"); + + VIAM_SDK_LOG(info) << "Getting motor: " << motor_name; + std::shared_ptr motor = robot->resource_by_name(motor_name); + + // Motors are always turned off if there is no attached client so this is expected to be 0 + VIAM_SDK_LOG(info) << "Motor power: " << motor->get_power_status().power_pct; + VIAM_SDK_LOG(info) << "Setting motor power to 50%"; + motor->set_power(0.5); + VIAM_SDK_LOG(info) << "Motor power: " << motor->get_power_status().power_pct; + + print_motor_position(motor); + + VIAM_SDK_LOG(info) << "Moving motor by 0.5 rotations at 10rpm"; + motor->go_for(10, 0.5); + + print_motor_position(motor); + + VIAM_SDK_LOG(info) << "Moving motor back to starting location"; + if (motor->get_properties().position_reporting) { + // More accurate + motor->go_to(10, 0); + } else { + // If position reporting is unavailable, we cannot call go_to + // but we can defer to reverting past actions + motor->go_for(10, -0.5); + } + + print_motor_position(motor); + + VIAM_SDK_LOG(info) << "Moving motor forward for 2 seconds at 30rpm"; + // With `revolutions`==0, the call will be non-blocking + // and the motor will rotate indefintely. + motor->go_for(30, 0); + + print_motor_position(motor); + + // Wait for 2 seconds, print position every 0.5 seconds + for (int i = 0; i < 4; i++) { + std::this_thread::sleep_for(std::chrono::milliseconds(500)); + print_motor_position(motor); + } + + // Explicitly stop the motor + VIAM_SDK_LOG(info) << "Stopping motor"; + motor->stop({}); + return EXIT_SUCCESS; +} catch (const std::exception& ex) { + std::cerr << "Program failed. Exception: " << std::string(ex.what()) << "\n"; + return EXIT_FAILURE; } diff --git a/src/viam/sdk/CMakeLists.txt b/src/viam/sdk/CMakeLists.txt index bd5edfa70..e450af13e 100644 --- a/src/viam/sdk/CMakeLists.txt +++ b/src/viam/sdk/CMakeLists.txt @@ -106,6 +106,8 @@ target_sources(viamsdk components/sensor.cpp components/servo.cpp config/resource.cpp + log/logging.cpp + log/private/log_backend.cpp module/handler_map.cpp module/module.cpp module/service.cpp @@ -174,6 +176,7 @@ target_sources(viamsdk ../../viam/sdk/components/sensor.hpp ../../viam/sdk/components/servo.hpp ../../viam/sdk/config/resource.hpp + ../../viam/sdk/log/logging.hpp ../../viam/sdk/module/handler_map.hpp ../../viam/sdk/module/module.hpp ../../viam/sdk/module/service.hpp @@ -248,6 +251,7 @@ viamcppsdk_link_viam_api(viamsdk PRIVATE) target_link_libraries(viamsdk PUBLIC Boost::headers PUBLIC Boost::log + PUBLIC Boost::log_setup PUBLIC xtensor PRIVATE ${VIAMCPPSDK_GRPCXX_REFLECTION_LIBRARIES} PRIVATE ${VIAMCPPSDK_GRPCXX_LIBRARIES} diff --git a/src/viam/sdk/common/client_helper.cpp b/src/viam/sdk/common/client_helper.cpp index b05bb37fe..a6853a748 100644 --- a/src/viam/sdk/common/client_helper.cpp +++ b/src/viam/sdk/common/client_helper.cpp @@ -5,9 +5,8 @@ #include #include -#include - #include +#include namespace viam { namespace sdk { @@ -15,8 +14,8 @@ namespace sdk { namespace client_helper_details { [[noreturn]] void errorHandlerReturnedUnexpectedly(const ::grpc::Status* status) noexcept { - BOOST_LOG_TRIVIAL(fatal) << "ClientHelper error handler callback returned instead of throwing: " - << status->error_message() << '(' << status->error_details() << ')'; + VIAM_SDK_LOG(fatal) << "ClientHelper error handler callback returned instead of throwing: " + << status->error_message() << '(' << status->error_details() << ')'; std::abort(); } diff --git a/src/viam/sdk/common/instance.cpp b/src/viam/sdk/common/instance.cpp index e3a84ea65..06baf29f4 100644 --- a/src/viam/sdk/common/instance.cpp +++ b/src/viam/sdk/common/instance.cpp @@ -27,6 +27,7 @@ Instance::Instance() { impl_ = std::make_unique(); impl_->registry.initialize(); + impl_->log_mgr.init_logging(); } Instance::~Instance() { diff --git a/src/viam/sdk/common/instance.hpp b/src/viam/sdk/common/instance.hpp index 096815943..de10ae896 100644 --- a/src/viam/sdk/common/instance.hpp +++ b/src/viam/sdk/common/instance.hpp @@ -28,6 +28,7 @@ class Instance { private: friend class Registry; + friend class LogManager; struct Impl; std::unique_ptr impl_; diff --git a/src/viam/sdk/common/private/instance.hpp b/src/viam/sdk/common/private/instance.hpp index b1728de8c..cb09480d9 100644 --- a/src/viam/sdk/common/private/instance.hpp +++ b/src/viam/sdk/common/private/instance.hpp @@ -1,6 +1,7 @@ #pragma once #include +#include #include namespace viam { @@ -8,6 +9,7 @@ namespace sdk { struct Instance::Impl { Registry registry; + LogManager log_mgr; }; } // namespace sdk diff --git a/src/viam/sdk/common/utils.cpp b/src/viam/sdk/common/utils.cpp index 5825c2e7f..42039d18f 100644 --- a/src/viam/sdk/common/utils.cpp +++ b/src/viam/sdk/common/utils.cpp @@ -10,9 +10,6 @@ #include #include -#include -#include -#include #include #include @@ -96,15 +93,6 @@ std::string bytes_to_string(const std::vector& b) { return img_string; } -void set_logger_severity_from_args(int argc, char** argv) { - if (argc >= 3 && strcmp(argv[2], "--log-level=debug") == 0) { - boost::log::core::get()->set_filter(boost::log::trivial::severity >= - boost::log::trivial::debug); - return; - } - boost::log::core::get()->set_filter(boost::log::trivial::severity >= boost::log::trivial::info); -} - std::string random_debug_key() { static const char alphanum[] = "abcdefghijklmnopqrstuvwxyz"; static std::default_random_engine generator( diff --git a/src/viam/sdk/common/utils.hpp b/src/viam/sdk/common/utils.hpp index f5067de55..51e360042 100644 --- a/src/viam/sdk/common/utils.hpp +++ b/src/viam/sdk/common/utils.hpp @@ -110,16 +110,6 @@ ProtoStruct with_debug_entry(ProtoStruct&& map, std::string debug_key); /// @returns the new ProtoStruct ProtoStruct with_debug_entry(ProtoStruct&& map); -/// @brief Set the boost trivial logger's severity depending on args. -/// @param argc The number of args. -/// @param argv The commandline arguments to parse. -/// -/// Sets the boost trivial logger's severity to debug if "--log-level=debug" is the -/// the third argument. Sets severity to info otherwise. Useful for module -/// implementations. See LogLevel documentation in the RDK for more information on -/// how to start modules with a "log-level" commandline argument. -void set_logger_severity_from_args(int argc, char** argv); - /// @brief Used in modular filter components to get the 'fromDataManagement' value from an extra /// ProtoStruct. /// @param extra The extra ProtoStruct. diff --git a/src/viam/sdk/config/resource.cpp b/src/viam/sdk/config/resource.cpp index 00d0296f7..8f19dadef 100644 --- a/src/viam/sdk/config/resource.cpp +++ b/src/viam/sdk/config/resource.cpp @@ -26,14 +26,16 @@ ResourceConfig::ResourceConfig(std::string type, ProtoStruct attributes, std::string api, Model model, - LinkConfig frame) + LinkConfig frame, + log_level lvl) : api_({kRDK, type, ""}), frame_(std::move(frame)), model_(std::move(model)), name_(std::move(name)), namespace__(std::move(namespace_)), type_(std::move(type)), - attributes_(std::move(attributes)) { + attributes_(std::move(attributes)), + log_level_(lvl) { if (api.find(':') != std::string::npos) { api_ = API::from_string(std::move(api)); } @@ -81,6 +83,10 @@ const std::string& ResourceConfig::type() const { return type_; } +log_level ResourceConfig::get_log_level() const { + return log_level_; +} + const std::vector& viam::sdk::ResourceConfig::depends_on() const { return depends_on_; } @@ -137,6 +143,7 @@ void to_proto_impl::operator()(const ResourceConfig& self, *proto->mutable_namespace_() = self.namespace_(); *proto->mutable_type() = self.type(); *proto->mutable_api() = self.api().to_string(); + *proto->mutable_log_configuration()->mutable_level() = to_string(self.get_log_level()); *proto->mutable_model() = self.model().to_string(); *proto->mutable_attributes() = to_proto(self.attributes()); @@ -154,7 +161,10 @@ ResourceConfig from_proto_impl::operator()( from_proto(proto->attributes()), proto->api(), Model::from_str(proto->model()), - proto->has_frame() ? from_proto(proto->frame()) : LinkConfig{}); + proto->has_frame() ? from_proto(proto->frame()) : LinkConfig{}, + proto->has_log_configuration() + ? level_from_string(proto->log_configuration().level()) + : log_level::info); } std::vector diff --git a/src/viam/sdk/config/resource.hpp b/src/viam/sdk/config/resource.hpp index 73b5c8450..d2531b5ff 100644 --- a/src/viam/sdk/config/resource.hpp +++ b/src/viam/sdk/config/resource.hpp @@ -5,6 +5,7 @@ #include #include +#include #include #include @@ -45,34 +46,54 @@ class ResourceConfig { ProtoStruct attributes, std::string api, Model model, - LinkConfig frame); + LinkConfig frame, + log_level lvl = sdk::log_level::info); ResourceConfig(std::string type); Name resource_name(); + const API& api() const; + const LinkConfig& frame() const; + const Model& model() const; + const std::string& name() const; const std::string& namespace_() const; const std::string& type() const; + + log_level get_log_level() const; + const std::vector& depends_on() const; + const std::vector& service_config() const; + const ProtoStruct& attributes() const; private: + void fix_api(); + API api_; + LinkConfig frame_; + Model model_; + std::string name_; std::string namespace__; std::string type_; + std::vector depends_on_; + std::vector service_config_; + ProtoStruct attributes_; ProtoValue converted_attributes_; + std::vector implicit_depends_on_; - void fix_api(); + + log_level log_level_; }; namespace proto_convert_details { diff --git a/src/viam/sdk/config/viam-cpp-sdk-libviamsdk.pc.in b/src/viam/sdk/config/viam-cpp-sdk-libviamsdk.pc.in index 005af602e..a042d0010 100644 --- a/src/viam/sdk/config/viam-cpp-sdk-libviamsdk.pc.in +++ b/src/viam/sdk/config/viam-cpp-sdk-libviamsdk.pc.in @@ -7,6 +7,5 @@ Description: @PROJECT_DESCRIPTION@ URL: @PROJECT_HOMEPAGE_URL@ Version: @PROJECT_VERSION@ Requires: grpc++ >= @VIAMCPPSDK_GRPCXX_VERSION@ protobuf >= @VIAMCPPSDK_PROTOBUF_VERSION@ @PROJECT_NAME@-libviamapi >= @PROJECT_VERSION@ -Libs: -L${libdir} -L@Boost_LIBRARY_DIRS@ -lviamsdk -lviam_rust_utils -Libs.private: -lboost_log-mt +Libs: -L${libdir} -L@Boost_LIBRARY_DIRS@ -lviamsdk -lviam_rust_utils -lboost_log -lboost_log_setup Cflags: -I${includedir} -I@Boost_INCLUDE_DIR@ diff --git a/src/viam/sdk/log/logging.cpp b/src/viam/sdk/log/logging.cpp new file mode 100644 index 000000000..910636e80 --- /dev/null +++ b/src/viam/sdk/log/logging.cpp @@ -0,0 +1,177 @@ +#include + +#include + +#include +#include +#include +#include +#include +#include +#include + +#include +#include +#include + +namespace viam { +namespace sdk { + +std::string to_string(log_level lvl) { + switch (lvl) { + case log_level::trace: + return "trace"; + case log_level::debug: + return "debug"; + case log_level::info: + return "info"; + case log_level::warn: + return "warning"; + // RDK does not support fatal so we send error regardless + case log_level::error: // fallthrough + case log_level::fatal: + return "error"; + default: + return std::to_string(static_cast>(lvl)); + } +} + +log_level level_from_string(std::string level) { + using ll = log_level; + + std::transform(level.begin(), level.end(), level.begin(), ::tolower); + + if (level == "info") { + return ll::info; + } else if (level == "warn" || level == "warning") { + return ll::warn; + } else if (level == "error") { + return ll::error; + } else if (level == "debug") { + return ll::debug; + } else if (level == "trace") { + return ll::trace; + } else if (level == "fatal") { + return ll::fatal; + } + + VIAM_SDK_LOG(warn) << "Returning unknown log level `" << level << "` as info"; + return ll::info; +} + +std::ostream& operator<<(std::ostream& os, log_level lvl) { + os << to_string(lvl); + return os; +} + +const char* global_resource_name() { + return "Viam C++ SDK"; +} + +bool LogManager::Filter::operator()(const boost::log::attribute_value_set& attrs) const { + auto sev = attrs[attr_sev_type{}]; + if (!sev) { + return false; + } + + auto resource = attrs[attr_channel_type{}]; + if (resource) { + auto it = parent->resource_levels_.find(*resource); + if (it != parent->resource_levels_.end()) { + return *sev >= it->second; + } + } + + return *sev >= parent->global_level_; +} + +LogManager& LogManager::get() { + static LogManager& result = Instance::current(Instance::Creation::open_existing).impl_->log_mgr; + + return result; +} + +void LogManager::set_global_resource_name(const std::string& name) { + sdk_logger_.channel(name); + VIAM_SDK_LOG(debug) << "Overrode global resource name"; +} + +LogSource& LogManager::global_logger() { + return sdk_logger_; +} + +void LogManager::set_global_log_level(log_level lvl) { + global_level_ = lvl; +} + +void LogManager::set_global_log_level(int argc, char** argv) { + if (argc >= 3 && strcmp(argv[2], "--log-level=debug") == 0) { + set_global_log_level(log_level::debug); + } +} + +void LogManager::set_resource_log_level(const std::string& resource, log_level lvl) { + resource_levels_[resource] = lvl; +} + +void LogManager::init_logging() { + sdk_logger_.channel(global_resource_name()); + boost::log::core::get()->add_global_attribute("TimeStamp", + boost::log::attributes::local_clock()); + + const boost::log::formatter fmt = + boost::log::expressions::stream + << boost::log::expressions::format_date_time( + "TimeStamp", "%Y--%m--%d %H:%M:%S") + << ": [" << attr_channel_type{} << "] <" << attr_sev_type{} << "> [" << attr_file_type{} + << ":" << attr_line_type{} << "] " << boost::log::expressions::smessage; + + auto backend = boost::make_shared(); + backend->add_stream(boost::shared_ptr(&std::cout, boost::null_deleter())); + backend->auto_flush(true); + + console_sink_ = boost::make_shared< + boost::log::sinks::synchronous_sink>(backend); + + console_sink_->set_filter(Filter{this}); + console_sink_->set_formatter(fmt); + + boost::log::core::get()->add_sink(console_sink_); + VIAM_SDK_LOG(debug) << "Initialized console logging"; +} + +void LogManager::disable_console_logging() { + VIAM_SDK_LOG(debug) << "Disabling console logging"; + + // Set a filter which ignores all console logs unless they contain a console force flag which is + // set to true. + console_sink_->set_filter( + [filter = Filter{this}](const boost::log::attribute_value_set& attrs) { + auto force = attrs[impl::attr_console_force_type{}]; + if (force && *force) { + return filter(attrs); + } + + return false; + }); +} + +namespace log_detail { + +boost::string_view trim_filename(const char* file) { + const boost::string_view result(file); + const std::size_t second_last = result // + .substr(0, result.find_last_of('/')) + .find_last_of('/'); + + if (second_last != boost::string_view::npos) { + return result.substr(second_last + 1, result.size() - second_last); + } + + return result; +} + +} // namespace log_detail + +} // namespace sdk +} // namespace viam diff --git a/src/viam/sdk/log/logging.hpp b/src/viam/sdk/log/logging.hpp new file mode 100644 index 000000000..9103b2033 --- /dev/null +++ b/src/viam/sdk/log/logging.hpp @@ -0,0 +1,161 @@ +/// @file log/logging.hpp +/// +/// @brief Defines logging infrastructure +#pragma once + +#include + +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include + +namespace viam { +namespace sdk { + +/// @defgroup Log Classes related to logging. + +/// @brief Severity levels for the logger. +/// @ingroup Log +enum class log_level : std::int8_t { + trace = -2, + debug = -1, + info = 0, // default value is info + warn = 1, + error = 2, + fatal = 3, +}; + +std::string to_string(log_level); + +log_level level_from_string(std::string level); + +std::ostream& operator<<(std::ostream&, log_level); + +/// @brief Type alias for the log source in the C++ SDK. +/// @ingroup Log +/// +/// In the paradigm of Boost.Log the C++ SDK has precisely one logging source, namely the source of +/// messages generated by the user invoking one of the logging macros. +using LogSource = boost::log::sources::severity_channel_logger_mt; + +/// @brief Returns the "channel name" of general log messages not originating from resources. +/// @ingroup Log +const char* global_resource_name(); + +/// @class LogManager logging.hpp "log/logging.hpp" +/// @brief Manages the logging infrastructure in the SDDK. +/// @ingroup Log +/// +/// Handles initialization and bookkeeping for logging infrastructure in the C++ SDK. This includes +/// console logging, if active, and both global and resource-level log filtering. +class LogManager { + public: + struct Filter { + const LogManager* parent; + + bool operator()(const boost::log::attribute_value_set&) const; + }; + + /// @brief Returns the unique logger instance. + /// + /// This is the only way to access the logger. + static LogManager& get(); + + /// @brief Override the channel name of general log messages not originating from resources. + void set_global_resource_name(const std::string& name); + + /// @brief Set the global logger severity. + void set_global_log_level(log_level); + + /// @brief Set the global logger severity from a command line argument vector. + /// + /// Sets severity to debug if "--log-level=debug" is + /// the third argument. Sets severity to info otherwise. Useful for module + /// implementations. See LogLevel documentation in the RDK for more information on + /// how to start modules with a "log-level" commandline argument. + void set_global_log_level(int argc, char** argv); + + /// @brief Set the logger severity for a resource. + /// + /// LogManager can maintain separate severity levels for individual resources. For example, you + /// may want to only report "error" messages for global logs and logs for one component of a + /// modular resource, but enable verbose logging for a new component that is still being + /// debugged. + /// @see @ref Resource, which has a set_log_level method which automatically provides its own + /// resource name. + void set_resource_log_level(const std::string& resource, log_level); + + /// @brief Return the SDK global log source. + /// + /// Users should prefer to log messages using the logging macros below. + LogSource& global_logger(); + + private: + friend class RobotClient; + friend class Instance; + LogManager() = default; + + LogManager(const LogManager&) = delete; + LogManager(LogManager&&) = delete; + + LogManager& operator=(const LogManager&) = delete; + LogManager& operator=(LogManager&&) = delete; + + void init_logging(); + void disable_console_logging(); + + LogSource sdk_logger_; + boost::shared_ptr> + console_sink_; + + log_level global_level_{log_level::info}; + + std::map resource_levels_; +}; + +namespace log_detail { + +// Some of the filenames in the SDK are not unique, eg config/resource.hpp, resource/resource.hpp. +// This function trims a full filename /path/to/some/file.xpp to some/file.xpp +boost::string_view trim_filename(const char* file); + +} // namespace log_detail + +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_channel, "Channel", std::string); +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_sev, "Severity", viam::sdk::log_level); +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_file, "file", boost::string_view); +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_line, "line", unsigned int); +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_time, + "TimeStamp", + boost::log::attributes::local_clock::value_type); + +#define VIAM_SDK_LOG_IMPL(lg, level) \ + BOOST_LOG_SEV((lg), ::viam::sdk::log_level::level) \ + << ::boost::log::add_value(::viam::sdk::attr_file_type{}, \ + ::viam::sdk::log_detail::trim_filename(__FILE__)) \ + << ::boost::log::add_value(::viam::sdk::attr_line_type{}, __LINE__) + +/// @brief Log macro for general SDK logs. +/// @ingroup Log +/// +/// Use this macro to generate log messages pertaining to the SDK at large. +#define VIAM_SDK_LOG(level) VIAM_SDK_LOG_IMPL(::viam::sdk::LogManager::get().global_logger(), level) + +/// @brief Log macro for resource-level logs. +/// @ingroup Log +/// +/// This macro can only be called from the definition of a member function of a class inheriting +/// @ref Resource. It will log messages to the log source of that specific resource, allowing +/// resource-level log filtering. +#define VIAM_RESOURCE_LOG(level) VIAM_SDK_LOG_IMPL(this->logger_, level) + +} // namespace sdk +} // namespace viam diff --git a/src/viam/sdk/log/private/log_backend.cpp b/src/viam/sdk/log/private/log_backend.cpp new file mode 100644 index 000000000..6e917adc5 --- /dev/null +++ b/src/viam/sdk/log/private/log_backend.cpp @@ -0,0 +1,34 @@ +#include + +#include +#include + +namespace viam { +namespace sdk { +namespace impl { + +time_pt ptime_convert(const boost::posix_time::ptime& from) { + namespace posix_time = boost::posix_time; + + posix_time::time_duration const time_since_epoch = from - posix_time::from_time_t(0); + const time_pt t = std::chrono::system_clock::from_time_t(time_since_epoch.total_seconds()); + const long nsec = time_since_epoch.fractional_seconds() * + (1000000000 / posix_time::time_duration::ticks_per_second()); + return t + std::chrono::nanoseconds(nsec); +} + +void LogBackend::consume(const boost::log::record_view& rec) const { + parent->log(*rec[attr_channel_type{}], + to_string(*rec[attr_sev_type{}]), + *rec[boost::log::expressions::smessage], + ptime_convert(*rec[attr_time_type{}])); +} + +boost::shared_ptr LogBackend::create(RobotClient* p) { + auto backend = boost::make_shared(p); + return boost::make_shared(backend); +} + +} // namespace impl +} // namespace sdk +} // namespace viam diff --git a/src/viam/sdk/log/private/log_backend.hpp b/src/viam/sdk/log/private/log_backend.hpp new file mode 100644 index 000000000..73e26fc3f --- /dev/null +++ b/src/viam/sdk/log/private/log_backend.hpp @@ -0,0 +1,35 @@ +#pragma once + +#include +#include +#include + +#include + +namespace viam { +namespace sdk { +namespace impl { + +struct LogBackend; + +using SinkType = boost::log::sinks::synchronous_sink; + +// Log backend which implements sending messages to RDK. +struct LogBackend : boost::log::sinks::basic_sink_backend { + LogBackend(RobotClient* p) : parent(p) {} + + void consume(const boost::log::record_view&) const; + + static boost::shared_ptr create(RobotClient* p); + + RobotClient* parent; +}; + +// TBD if we want to expose this to users, but for now it is an implementation detail. +// Disabling console logging is implemented by changing the filter on the console sink to reject all +// messages unless they have a "force" flag set to true. +BOOST_LOG_ATTRIBUTE_KEYWORD_TYPE(attr_console_force, "force", bool); + +} // namespace impl +} // namespace sdk +} // namespace viam diff --git a/src/viam/sdk/module/handler_map.cpp b/src/viam/sdk/module/handler_map.cpp index 4d2ba34bf..44a902e66 100644 --- a/src/viam/sdk/module/handler_map.cpp +++ b/src/viam/sdk/module/handler_map.cpp @@ -2,8 +2,6 @@ #include -#include - #include #include #include @@ -66,7 +64,7 @@ HandlerMap_ from_proto_impl::operator()( try { hm.add_model(Model::from_str(mod), handle); } catch (const std::exception& ex) { - BOOST_LOG_TRIVIAL(error) << "Error " << ex.what() << " processing model " + mod; + VIAM_SDK_LOG(error) << "Error " << ex.what() << " processing model " + mod; } } } diff --git a/src/viam/sdk/module/module.cpp b/src/viam/sdk/module/module.cpp index 3c09df767..7af0fa34b 100644 --- a/src/viam/sdk/module/module.cpp +++ b/src/viam/sdk/module/module.cpp @@ -1,6 +1,5 @@ #include -#include #include #include #include @@ -10,7 +9,7 @@ namespace viam { namespace sdk { -Module::Module(std::string addr) : addr_(std::move(addr)){}; +Module::Module(std::string addr) : addr_(std::move(addr)) {} void Module::set_ready() { ready_ = true; diff --git a/src/viam/sdk/module/service.cpp b/src/viam/sdk/module/service.cpp index 911be9bb3..c22e21fe9 100644 --- a/src/viam/sdk/module/service.cpp +++ b/src/viam/sdk/module/service.cpp @@ -7,7 +7,6 @@ #include #include -#include #include #include #include @@ -61,6 +60,7 @@ struct ModuleService::ServiceImpl : viam::module::v1::ModuleService::Service { if (reg) { try { res = reg->construct_resource(deps, cfg); + res->set_log_level(cfg.get_log_level()); } catch (const std::exception& exc) { return grpc::Status(::grpc::INTERNAL, exc.what()); } @@ -99,6 +99,7 @@ struct ModuleService::ServiceImpl : viam::module::v1::ModuleService::Service { } try { Reconfigurable::reconfigure_if_reconfigurable(res, deps, cfg); + res->set_log_level(cfg.get_log_level()); return grpc::Status(); } catch (const std::exception& exc) { return grpc::Status(::grpc::INTERNAL, exc.what()); @@ -108,7 +109,7 @@ struct ModuleService::ServiceImpl : viam::module::v1::ModuleService::Service { try { Stoppable::stop_if_stoppable(res); } catch (const std::exception& err) { - BOOST_LOG_TRIVIAL(error) << "unable to stop resource: " << err.what(); + VIAM_SDK_LOG(error) << "unable to stop resource: " << err.what(); } const std::shared_ptr reg = @@ -169,7 +170,7 @@ struct ModuleService::ServiceImpl : viam::module::v1::ModuleService::Service { try { Stoppable::stop_if_stoppable(res); } catch (const std::exception& err) { - BOOST_LOG_TRIVIAL(error) << "unable to stop resource: " << err.what(); + VIAM_SDK_LOG(error) << "unable to stop resource: " << err.what(); } manager->remove(name); @@ -182,7 +183,12 @@ struct ModuleService::ServiceImpl : viam::module::v1::ModuleService::Service { const std::lock_guard lock(parent.lock_); const viam::module::v1::HandlerMap hm = to_proto(parent.module_->handles()); *response->mutable_handlermap() = hm; - parent.parent_addr_ = request->parent_address(); + auto new_parent_addr = request->parent_address(); + if (parent.parent_addr_ != new_parent_addr) { + parent.parent_addr_ = std::move(new_parent_addr); + parent.parent_ = RobotClient::at_local_socket(parent.parent_addr_, {0, boost::none}); + parent.parent_->connect_logging(); + } response->set_ready(parent.module_->ready()); return grpc::Status(); } @@ -208,7 +214,9 @@ Dependencies ModuleService::get_dependencies_( std::shared_ptr ModuleService::get_parent_resource_(const Name& name) { if (!parent_) { + // LS: I think maybe this is never hit parent_ = RobotClient::at_local_socket(parent_addr_, {0, boost::none}); + parent_->connect_logging(); } return parent_->resource_by_name(name); @@ -229,7 +237,7 @@ ModuleService::ModuleService(int argc, } return argv[1]; }()) { - set_logger_severity_from_args(argc, argv); + LogManager::get().set_global_log_level(argc, argv); for (auto&& mr : registrations) { Registry::get().register_model(mr); @@ -239,14 +247,14 @@ ModuleService::ModuleService(int argc, ModuleService::~ModuleService() { // TODO(RSDK-5509): Run registered cleanup functions here. - BOOST_LOG_TRIVIAL(info) << "Shutting down gracefully."; + VIAM_SDK_LOG(info) << "Shutting down gracefully."; server_->shutdown(); if (parent_) { try { parent_->close(); } catch (const std::exception& exc) { - BOOST_LOG_TRIVIAL(error) << exc.what(); + VIAM_SDK_LOG(error) << exc.what(); } } } @@ -264,9 +272,8 @@ void ModuleService::serve() { module_->set_ready(); server_->start(); - BOOST_LOG_TRIVIAL(info) << "Module listening on " << module_->addr(); - BOOST_LOG_TRIVIAL(info) << "Module handles the following API/model pairs:\n" - << module_->handles(); + VIAM_SDK_LOG(info) << "Module listening on " << module_->addr(); + VIAM_SDK_LOG(info) << "Module handles the following API/model pairs:\n" << module_->handles(); signal_manager_.wait(); } diff --git a/src/viam/sdk/module/service.hpp b/src/viam/sdk/module/service.hpp index 799ba1ab5..714d55051 100644 --- a/src/viam/sdk/module/service.hpp +++ b/src/viam/sdk/module/service.hpp @@ -65,10 +65,14 @@ class ModuleService { std::shared_ptr get_parent_resource_(const Name& name); std::mutex lock_; + std::unique_ptr module_; + std::shared_ptr parent_; std::string parent_addr_; + std::unique_ptr server_; + SignalManager signal_manager_; std::unique_ptr impl_; diff --git a/src/viam/sdk/registry/registry.cpp b/src/viam/sdk/registry/registry.cpp index 0943902f2..d844bf4b7 100644 --- a/src/viam/sdk/registry/registry.cpp +++ b/src/viam/sdk/registry/registry.cpp @@ -5,7 +5,6 @@ #include #include -#include #include #include #include diff --git a/src/viam/sdk/resource/resource.cpp b/src/viam/sdk/resource/resource.cpp index caf4b94d1..3408f0104 100644 --- a/src/viam/sdk/resource/resource.cpp +++ b/src/viam/sdk/resource/resource.cpp @@ -1,5 +1,7 @@ #include +#include + #include #include #include @@ -9,7 +11,8 @@ namespace viam { namespace sdk { Resource::~Resource() = default; -Resource::Resource(std::string name) : name_(std::move(name)) {} +Resource::Resource(std::string name) + : name_(std::move(name)), logger_(boost::log::keywords::channel = name_) {} std::string Resource::name() const { return name_; @@ -26,5 +29,9 @@ Name Resource::get_resource_name() const { return get_resource_name(kResource); } +void Resource::set_log_level(log_level ll) const { + LogManager::get().set_resource_log_level(name_, ll); +} + } // namespace sdk } // namespace viam diff --git a/src/viam/sdk/resource/resource.hpp b/src/viam/sdk/resource/resource.hpp index dcf9f4363..b6f31359b 100644 --- a/src/viam/sdk/resource/resource.hpp +++ b/src/viam/sdk/resource/resource.hpp @@ -4,13 +4,16 @@ #include #include +#include #include namespace viam { namespace sdk { class Resource; + using Dependencies = std::unordered_map>; + class Resource { public: virtual ~Resource(); @@ -25,11 +28,16 @@ class Resource { /// @brief Return the resource's name. virtual std::string name() const; + /// @brief Set the log level for log messages originating from this Resource. + void set_log_level(log_level) const; + private: std::string name_; protected: Name get_resource_name(const std::string& type) const; + + LogSource logger_; }; template <> diff --git a/src/viam/sdk/resource/resource_manager.cpp b/src/viam/sdk/resource/resource_manager.cpp index 8f2940c5f..40dc64ece 100644 --- a/src/viam/sdk/resource/resource_manager.cpp +++ b/src/viam/sdk/resource/resource_manager.cpp @@ -7,8 +7,6 @@ #include #include -#include -#include #include #include @@ -52,7 +50,7 @@ void ResourceManager::replace_all( try { do_add(resource.first, resource.second); } catch (std::exception& exc) { - BOOST_LOG_TRIVIAL(error) << "Error replacing all resources" << exc.what(); + VIAM_SDK_LOG(error) << "Error replacing all resources" << exc.what(); return; } } @@ -97,7 +95,7 @@ void ResourceManager::add(const Name& name, std::shared_ptr resource) try { do_add(name, std::move(resource)); } catch (std::exception& exc) { - BOOST_LOG_TRIVIAL(error) << "Error adding resource to subtype service: " << exc.what(); + VIAM_SDK_LOG(error) << "Error adding resource to subtype service: " << exc.what(); } }; @@ -134,7 +132,7 @@ void ResourceManager::remove(const Name& name) { try { do_remove(name); } catch (std::exception& exc) { - BOOST_LOG_TRIVIAL(error) << "unable to remove resource: " << exc.what(); + VIAM_SDK_LOG(error) << "unable to remove resource: " << exc.what(); }; }; @@ -144,8 +142,8 @@ void ResourceManager::replace_one(const Name& name, std::shared_ptr re do_remove(name); do_add(name, std::move(resource)); } catch (std::exception& exc) { - BOOST_LOG_TRIVIAL(error) << "failed to replace resource " << name.to_string() << ": " - << exc.what(); + VIAM_SDK_LOG(error) << "failed to replace resource " << name.to_string() << ": " + << exc.what(); } } diff --git a/src/viam/sdk/robot/client.cpp b/src/viam/sdk/robot/client.cpp index ab3789567..222870003 100644 --- a/src/viam/sdk/robot/client.cpp +++ b/src/viam/sdk/robot/client.cpp @@ -9,7 +9,7 @@ #include #include -#include +#include #include #include #include @@ -24,6 +24,7 @@ #include #include #include +#include #include #include #include @@ -84,17 +85,45 @@ bool operator==(const RobotClient::operation& lhs, const RobotClient::operation& struct RobotClient::impl { impl(std::unique_ptr stub) : stub_(std::move(stub)) {} + + ~impl() { + if (log_sink) { + boost::log::core::get()->remove_sink(log_sink); + } + } + std::unique_ptr stub_; + + boost::shared_ptr log_sink; }; +void RobotClient::connect_logging() { + auto& sink = impl_->log_sink; + if (!sink) { + sink = sdk::impl::LogBackend::create(this); + sink->set_filter([filter = LogManager::Filter{&LogManager::get()}]( + const boost::log::attribute_value_set& attrs) { + auto force = attrs[sdk::impl::attr_console_force_type{}]; + if (force && *force) { + return false; + } + + return filter(attrs); + }); + + LogManager::get().disable_console_logging(); + boost::log::core::get()->add_sink(sink); + } +} + RobotClient::~RobotClient() { if (should_close_channel_) { try { this->close(); } catch (const std::exception& e) { - BOOST_LOG_TRIVIAL(error) << "Received err while closing RobotClient: " << e.what(); + VIAM_SDK_LOG(error) << "Received err while closing RobotClient: " << e.what(); } catch (...) { - BOOST_LOG_TRIVIAL(error) << "Received unknown err while closing RobotClient"; + VIAM_SDK_LOG(error) << "Received unknown err while closing RobotClient"; } } } @@ -121,7 +150,7 @@ std::vector RobotClient::get_operations() { grpc::Status const response = impl_->stub_->GetOperations(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error getting operations: " << response.error_message(); + VIAM_SDK_LOG(error) << "Error getting operations: " << response.error_message(); } for (int i = 0; i < resp.operations().size(); ++i) { @@ -139,7 +168,7 @@ void RobotClient::cancel_operation(std::string id) { req.set_id(id); const grpc::Status response = impl_->stub_->CancelOperation(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error canceling operation with id " << id; + VIAM_SDK_LOG(error) << "Error canceling operation with id " << id; } } @@ -152,7 +181,7 @@ void RobotClient::block_for_operation(std::string id) { const grpc::Status response = impl_->stub_->BlockForOperation(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error blocking for operation with id " << id; + VIAM_SDK_LOG(error) << "Error blocking for operation with id " << id; } } @@ -163,7 +192,7 @@ void RobotClient::refresh() { const grpc::Status response = impl_->stub_->ResourceNames(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error getting resource names: " << response.error_message(); + VIAM_SDK_LOG(error) << "Error getting resource names: " << response.error_message(); } std::unordered_map> new_resources; @@ -187,7 +216,7 @@ void RobotClient::refresh() { const Name name_({name.namespace_(), name.type(), name.subtype()}, "", name.name()); new_resources.emplace(name_, rpc_client); } catch (const std::exception& exc) { - BOOST_LOG_TRIVIAL(debug) + VIAM_SDK_LOG(debug) << "Error registering component " << name.subtype() << ": " << exc.what(); } } @@ -233,6 +262,31 @@ std::vector RobotClient::resource_names() const { return resource_names_; } +void RobotClient::log(const std::string& name, + const std::string& level, + const std::string& message, + time_pt time) { + robot::v1::LogRequest req; + common::v1::LogEntry log; + + *log.mutable_logger_name() = name; + log.set_level(level); + *log.mutable_message() = message; + *log.mutable_time() = to_proto(time); + req.mutable_logs()->Add(std::move(log)); + + robot::v1::LogResponse resp; + ClientContext ctx; + const auto response = impl_->stub_->Log(ctx, req, &resp); + if (is_error_response(response)) { + // Manually override to force this to get logged to console so we don't set off an infinite + // loop + VIAM_SDK_LOG(error) << boost::log::add_value(sdk::impl::attr_console_force_type{}, true) + << "Error sending log message over grpc: " << response.error_message() + << response.error_details(); + } +} + std::shared_ptr RobotClient::with_channel(std::shared_ptr channel, const Options& options) { std::shared_ptr robot = std::make_shared(std::move(channel)); @@ -285,8 +339,7 @@ std::vector RobotClient::get_frame_system_conf const grpc::Status response = impl_->stub_->FrameSystemConfig(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error getting frame system config: " - << response.error_message(); + VIAM_SDK_LOG(error) << "Error getting frame system config: " << response.error_message(); } const RepeatedPtrField configs = resp.frame_system_configs(); @@ -314,7 +367,7 @@ pose_in_frame RobotClient::transform_pose( const grpc::Status response = impl_->stub_->TransformPose(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error getting PoseInFrame: " << response.error_message(); + VIAM_SDK_LOG(error) << "Error getting PoseInFrame: " << response.error_message(); } return from_proto(resp.pose()); @@ -349,8 +402,8 @@ void RobotClient::stop_all(const std::unordered_map& extra) { } const grpc::Status response = impl_->stub_->StopAll(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error stopping all: " << response.error_message() - << response.error_details(); + VIAM_SDK_LOG(error) << "Error stopping all: " << response.error_message() + << response.error_details(); } } @@ -378,8 +431,8 @@ RobotClient::status RobotClient::get_machine_status() const { const grpc::Status response = impl_->stub_->GetMachineStatus(ctx, req, &resp); if (is_error_response(response)) { - BOOST_LOG_TRIVIAL(error) << "Error getting machine status: " << response.error_message() - << response.error_details(); + VIAM_SDK_LOG(error) << "Error getting machine status: " << response.error_message() + << response.error_details(); } switch (resp.state()) { case robot::v1::GetMachineStatusResponse_State_STATE_INITIALIZING: diff --git a/src/viam/sdk/robot/client.hpp b/src/viam/sdk/robot/client.hpp index 50fda612c..8b00d4250 100644 --- a/src/viam/sdk/robot/client.hpp +++ b/src/viam/sdk/robot/client.hpp @@ -20,6 +20,10 @@ namespace viam { namespace sdk { +namespace impl { +struct LogBackend; +} + /// @defgroup Robot Classes related to a Robot representation. /// @class RobotClient client.hpp "robot/client.hpp" @@ -85,7 +89,9 @@ class RobotClient { /// `close()`d manually. static std::shared_ptr with_channel(std::shared_ptr channel, const Options& options); + RobotClient(std::shared_ptr channel); + std::vector resource_names() const; /// @brief Lookup and return a `shared_ptr` to a resource. @@ -147,6 +153,16 @@ class RobotClient { status get_machine_status() const; private: + friend class ModuleService; + friend struct impl::LogBackend; + + void log(const std::string& name, + const std::string& level, + const std::string& message, + time_pt time); + + void connect_logging(); + void refresh_every(); std::vector> threads_; diff --git a/src/viam/sdk/rpc/server.cpp b/src/viam/sdk/rpc/server.cpp index 9964abbac..c16394b26 100644 --- a/src/viam/sdk/rpc/server.cpp +++ b/src/viam/sdk/rpc/server.cpp @@ -2,8 +2,6 @@ #include -#include - #include #include #include diff --git a/src/viam/sdk/tests/CMakeLists.txt b/src/viam/sdk/tests/CMakeLists.txt index 605599f4a..201100e42 100644 --- a/src/viam/sdk/tests/CMakeLists.txt +++ b/src/viam/sdk/tests/CMakeLists.txt @@ -64,6 +64,7 @@ viamcppsdk_add_boost_test(test_discovery.cpp) viamcppsdk_add_boost_test(test_gantry.cpp) viamcppsdk_add_boost_test(test_gripper.cpp) viamcppsdk_add_boost_test(test_generics.cpp) +viamcppsdk_add_boost_test(test_log.cpp) viamcppsdk_add_boost_test(test_mlmodel.cpp) viamcppsdk_add_boost_test(test_motor.cpp) viamcppsdk_add_boost_test(test_motion.cpp) diff --git a/src/viam/sdk/tests/test_log.cpp b/src/viam/sdk/tests/test_log.cpp new file mode 100644 index 000000000..da52b3733 --- /dev/null +++ b/src/viam/sdk/tests/test_log.cpp @@ -0,0 +1,154 @@ +#define BOOST_TEST_MODULE test module test_log +#include + +#include + +#include +#include + +#include +#include +#include + +namespace viam { +namespace sdktests { + +BOOST_AUTO_TEST_CASE(test_cout_logging) { + cout_redirect redirect; + + VIAM_SDK_LOG(info) << "log1"; + + using namespace std::string_literals; + + const std::string rec = redirect.os.str(); + redirect.release(); + + for (const std::string& s : + {"log1"s, to_string(sdk::log_level::info), std::string{sdk::global_resource_name()}}) { + BOOST_CHECK(rec.find(s) != std::string::npos); + } +} + +BOOST_AUTO_TEST_CASE(test_global_name) { + cout_redirect redirect; + + sdk::LogManager::get().set_global_resource_name("My Channel"); + + VIAM_SDK_LOG(info) << "after"; + + const std::string rec = redirect.os.str(); + redirect.release(); + + for (const char* s : {"My Channel", "after"}) { + BOOST_CHECK(rec.find(s) != std::string::npos); + } + + BOOST_CHECK(rec.find(sdk::global_resource_name()) == std::string::npos); +} + +BOOST_AUTO_TEST_CASE(test_global_filter) { + cout_redirect redirect; + + VIAM_SDK_LOG(info) << "info1"; + VIAM_SDK_LOG(error) << "error1"; + VIAM_SDK_LOG(trace) << "trace1"; // not logged + + auto& logger = sdk::LogManager::get(); + + using ll = sdk::log_level; + + logger.set_global_log_level(ll::trace); + + VIAM_SDK_LOG(trace) << "trace2"; + VIAM_SDK_LOG(info) << "info2"; + + logger.set_global_log_level(ll::error); + + VIAM_SDK_LOG(info) << "info3"; // not logged + VIAM_SDK_LOG(error) << "error2"; + + logger.set_global_log_level(ll::info); + + VIAM_SDK_LOG(info) << "info4"; + VIAM_SDK_LOG(trace) << "trace3"; // once again not logged + + const std::string rec = redirect.os.str(); + redirect.release(); + + for (const char* logged : {"info1", "error1", "trace2", "info2", "error2", "info4"}) { + BOOST_TEST_INFO("Checking for " << logged << " in log rec\n" << rec); + BOOST_CHECK(rec.find(logged) != std::string::npos); + } + + for (const char* not_logged : {"trace1", "info3", "trace3"}) { + BOOST_TEST_INFO("Checking for " << not_logged << " not in log rec\n" << rec); + BOOST_CHECK(rec.find(not_logged) == std::string::npos); + } +} + +struct LogSensor : sensor::MockSensor { + using sensor::MockSensor::MockSensor; + + sdk::ProtoStruct get_readings(const sdk::ProtoStruct& extra) override { + VIAM_RESOURCE_LOG(info) << "sensor info"; + VIAM_RESOURCE_LOG(error) << "sensor error"; + return sensor::MockSensor::get_readings(extra); + } +}; + +BOOST_AUTO_TEST_CASE(test_resource_filter) { + cout_redirect redirect; + + auto defaultSensor = std::make_shared("DefaultSensor"); + auto errorSensor = std::make_shared("ErrorSensor"); + errorSensor->set_log_level(sdk::log_level::error); + + for (auto sensor : {defaultSensor, errorSensor}) { + client_to_mock_pipeline(sensor, + [&](Sensor& client) { (void)client.get_readings({}); }); + } + + std::vector defaultLogs; + std::vector errLogs; + + const std::string rec = redirect.os.str(); + BOOST_TEST_INFO("Log records\n" << rec); + + std::stringstream ss(rec); + redirect.release(); + + { + std::string local; + + while (std::getline(ss, local, '\n')) { + if (local.find("DefaultSensor") != std::string::npos) { + defaultLogs.push_back(std::move(local)); + } else if (local.find("ErrorSensor") != std::string::npos) { + errLogs.push_back(std::move(local)); + } + } + } + + BOOST_ASSERT(defaultLogs.size() == 2); + { + BOOST_TEST_MESSAGE("default logs\n" << defaultLogs.front() << "\n" << defaultLogs.back()); + BOOST_CHECK(defaultLogs.front().find("sensor info") != std::string::npos); + BOOST_CHECK(defaultLogs.back().find("sensor error") != std::string::npos); + } + + BOOST_ASSERT(errLogs.size() == 1); + BOOST_CHECK(errLogs.back().find("sensor error") != std::string::npos); +} + +BOOST_AUTO_TEST_CASE(filename_trim) { + using namespace log_detail; + + BOOST_CHECK(trim_filename("") == ""); + BOOST_CHECK(trim_filename("no_delim") == "no_delim"); + BOOST_CHECK(trim_filename("one/slash.cpp") == "one/slash.cpp"); + BOOST_CHECK(trim_filename("a/full/path.cpp") == "full/path.cpp"); + BOOST_CHECK(trim_filename("a/b/c/d.cpp") == "c/d.cpp"); +} + +} // namespace sdktests +} // namespace viam diff --git a/src/viam/sdk/tests/test_utils.hpp b/src/viam/sdk/tests/test_utils.hpp index bb69e2499..a06de3a30 100644 --- a/src/viam/sdk/tests/test_utils.hpp +++ b/src/viam/sdk/tests/test_utils.hpp @@ -21,6 +21,27 @@ struct GlobalFixture { BOOST_TEST_GLOBAL_FIXTURE(GlobalFixture); +// Buffer output filter to test console logging. +// In practice this is a pain and makes it hard to inspect Boost.Test output, +// so rather than using it as a test fixture we manually instantiate it and call release when done. +// https://stackoverflow.com/a/5405268 +struct cout_redirect { + cout_redirect() : old(std::cout.rdbuf(os.rdbuf())) {} + + void release() { + std::cout.rdbuf(old); + } + + ~cout_redirect() { + release(); + } + + std::ostringstream os; + + private: + std::streambuf* old; +}; + using namespace viam::sdk; ProtoStruct fake_map();