diff --git a/conda/environments/all_cuda-118_arch-x86_64.yaml b/conda/environments/all_cuda-118_arch-x86_64.yaml index 6f9734eb314..66d375910d4 100644 --- a/conda/environments/all_cuda-118_arch-x86_64.yaml +++ b/conda/environments/all_cuda-118_arch-x86_64.yaml @@ -27,6 +27,7 @@ dependencies: - dlpack>=0.5,<0.6.0a0 - doxygen=1.8.20 - fastavro>=0.22.9 +- fmt>=9.1.0,<10 - fsspec>=0.6.0 - gcc_linux-64=11.* - hypothesis @@ -68,6 +69,7 @@ dependencies: - s3fs>=2022.3.0 - scikit-build>=0.13.1 - scipy +- spdlog>=1.11.0,<1.12 - sphinx - sphinx-autobuild - sphinx-copybutton diff --git a/conda/recipes/libcudf/conda_build_config.yaml b/conda/recipes/libcudf/conda_build_config.yaml index 1111fc0a24e..3cd88de8e64 100644 --- a/conda/recipes/libcudf/conda_build_config.yaml +++ b/conda/recipes/libcudf/conda_build_config.yaml @@ -24,3 +24,9 @@ dlpack_version: librdkafka_version: - ">=1.7.0,<1.8.0a0" + +fmt_version: + - ">=9.1.0,<10" + +spdlog_version: + - ">=1.11.0,<1.12" diff --git a/conda/recipes/libcudf/meta.yaml b/conda/recipes/libcudf/meta.yaml index 309868b8144..770a234b56e 100644 --- a/conda/recipes/libcudf/meta.yaml +++ b/conda/recipes/libcudf/meta.yaml @@ -49,6 +49,8 @@ requirements: - libarrow {{ libarrow_version }} - dlpack {{ dlpack_version }} - librdkafka {{ librdkafka_version }} + - fmt {{ fmt_version }} + - spdlog {{ spdlog_version }} outputs: - name: libcudf @@ -128,6 +130,7 @@ outputs: - test -f $PREFIX/include/cudf/detail/utilities/int_fastdiv.h - test -f $PREFIX/include/cudf/detail/utilities/integer_utils.hpp - test -f $PREFIX/include/cudf/detail/utilities/linked_column.hpp + - test -f $PREFIX/include/cudf/detail/utilities/logger.hpp - test -f $PREFIX/include/cudf/detail/utilities/pinned_allocator.hpp - test -f $PREFIX/include/cudf/detail/utilities/vector_factories.hpp - test -f $PREFIX/include/cudf/detail/utilities/visitor_overload.hpp @@ -278,6 +281,7 @@ outputs: - test -f $PREFIX/include/cudf/utilities/bit.hpp - test -f $PREFIX/include/cudf/utilities/default_stream.hpp - test -f $PREFIX/include/cudf/utilities/error.hpp + - test -f $PREFIX/include/cudf/utilities/logger.hpp - test -f $PREFIX/include/cudf/utilities/span.hpp - test -f $PREFIX/include/cudf/utilities/traits.hpp - test -f $PREFIX/include/cudf/utilities/type_checks.hpp diff --git a/cpp/CMakeLists.txt b/cpp/CMakeLists.txt index 96524b7c55f..a261049d3f0 100644 --- a/cpp/CMakeLists.txt +++ b/cpp/CMakeLists.txt @@ -120,15 +120,16 @@ set(CUDF_CUDA_FLAGS "") set(CUDF_CXX_DEFINITIONS "") set(CUDF_CUDA_DEFINITIONS "") -# Set RMM logging level -set(RMM_LOGGING_LEVEL +# Set logging level +set(LIBCUDF_LOGGING_LEVEL "INFO" CACHE STRING "Choose the logging level." ) set_property( - CACHE RMM_LOGGING_LEVEL PROPERTY STRINGS "TRACE" "DEBUG" "INFO" "WARN" "ERROR" "CRITICAL" "OFF" + CACHE LIBCUDF_LOGGING_LEVEL PROPERTY STRINGS "TRACE" "DEBUG" "INFO" "WARN" "ERROR" "CRITICAL" + "OFF" ) -message(VERBOSE "CUDF: RMM_LOGGING_LEVEL = '${RMM_LOGGING_LEVEL}'.") +message(VERBOSE "CUDF: LIBCUDF_LOGGING_LEVEL = '${LIBCUDF_LOGGING_LEVEL}'.") if(NOT CUDF_GENERATED_INCLUDE_DIR) set(CUDF_GENERATED_INCLUDE_DIR ${CUDF_BINARY_DIR}) @@ -191,6 +192,10 @@ include(cmake/Modules/JitifyPreprocessKernels.cmake) include(cmake/thirdparty/get_cufile.cmake) # find KvikIO include(cmake/thirdparty/get_kvikio.cmake) +# find fmt +include(cmake/thirdparty/get_fmt.cmake) +# find spdlog +include(cmake/thirdparty/get_spdlog.cmake) # Workaround until https://github.com/rapidsai/rapids-cmake/issues/176 is resolved if(NOT BUILD_SHARED_LIBS) @@ -597,6 +602,7 @@ add_library( src/unary/nan_ops.cu src/unary/null_ops.cu src/utilities/default_stream.cpp + src/utilities/logger.cpp src/utilities/traits.cpp src/utilities/type_checks.cpp src/utilities/type_dispatcher.cpp @@ -677,8 +683,11 @@ if(NOT USE_NVTX) target_compile_definitions(cudf PUBLIC NVTX_DISABLE) endif() +# Define RMM logging level +target_compile_definitions(cudf PRIVATE "RMM_LOGGING_LEVEL=LIBCUDF_LOGGING_LEVEL") + # Define spdlog level -target_compile_definitions(cudf PUBLIC "SPDLOG_ACTIVE_LEVEL=SPDLOG_LEVEL_${RMM_LOGGING_LEVEL}") +target_compile_definitions(cudf PUBLIC "SPDLOG_ACTIVE_LEVEL=SPDLOG_LEVEL_${LIBCUDF_LOGGING_LEVEL}") # Compile stringified JIT sources first add_dependencies(cudf jitify_preprocess_run) diff --git a/cpp/cmake/thirdparty/get_fmt.cmake b/cpp/cmake/thirdparty/get_fmt.cmake new file mode 100644 index 00000000000..083dd1d0631 --- /dev/null +++ b/cpp/cmake/thirdparty/get_fmt.cmake @@ -0,0 +1,22 @@ +# ============================================================================= +# Copyright (c) 2023, NVIDIA CORPORATION. +# +# 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. +# ============================================================================= + +# Use CPM to find or clone fmt +function(find_and_configure_fmt) + + include(${rapids-cmake-dir}/cpm/fmt.cmake) + rapids_cpm_fmt(INSTALL_EXPORT_SET cudf-exports BUILD_EXPORT_SET cudf-exports) +endfunction() + +find_and_configure_fmt() diff --git a/cpp/cmake/thirdparty/get_spdlog.cmake b/cpp/cmake/thirdparty/get_spdlog.cmake new file mode 100644 index 00000000000..fff5b84af0d --- /dev/null +++ b/cpp/cmake/thirdparty/get_spdlog.cmake @@ -0,0 +1,34 @@ +# ============================================================================= +# Copyright (c) 2023, NVIDIA CORPORATION. +# +# 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. +# ============================================================================= + +# Use CPM to find or clone speedlog +function(find_and_configure_spdlog) + + include(${rapids-cmake-dir}/cpm/spdlog.cmake) + rapids_cpm_spdlog(FMT_OPTION "EXTERNAL_FMT_HO" INSTALL_EXPORT_SET cudf-exports) + rapids_export_package(BUILD spdlog cudf-exports) + + if(spdlog_ADDED) + rapids_export( + BUILD spdlog + EXPORT_SET spdlog + GLOBAL_TARGETS spdlog spdlog_header_only + NAMESPACE spdlog:: + ) + include("${rapids-cmake-dir}/export/find_package_root.cmake") + rapids_export_find_package_root(BUILD spdlog [=[${CMAKE_CURRENT_LIST_DIR}]=] cudf-exports) + endif() +endfunction() + +find_and_configure_spdlog() diff --git a/cpp/doxygen/developer_guide/DEVELOPER_GUIDE.md b/cpp/doxygen/developer_guide/DEVELOPER_GUIDE.md index 3c3d5358e43..8cd4f8c6d27 100644 --- a/cpp/doxygen/developer_guide/DEVELOPER_GUIDE.md +++ b/cpp/doxygen/developer_guide/DEVELOPER_GUIDE.md @@ -901,6 +901,46 @@ void trivial_types_only(T t){ } ``` +# Logging + +libcudf includes logging utilities (built on top of [spdlog](https://github.com/gabime/spdlog) +library), which should be used to log important events (e.g. user warnings). This utility can also +be used to log debug information, as long as the correct logging level is used. There are six macros +that should be used for logging at different levels: + +* `CUDF_LOG_TRACE` - verbose debug messages (targeted at developers) +* `CUDF_LOG_DEBUG` - debug messages (targeted at developers) +* `CUDF_LOG_INFO` - information about rare events (e.g. once per run) that occur during normal +execution +* `CUDF_LOG_WARN` - user warnings about potentially unexpected behavior or deprecations +* `CUDF_LOG_ERROR` - recoverable errors +* `CUDF_LOG_CRITICAL` - unrecoverable errors (e.g. memory corruption) + +By default, `TRACE`, `DEBUG` and `INFO` messages are excluded from the log. In addition, in public +builds, the code that logs at `TRACE` and `DEBUG` levels is compiled out. This prevents logging of +potentially sensitive data that might be done for debug purposes. Also, this allows developers to +include expensive computation in the trace/debug logs, as the overhead will not be present in the +public builds. +The minimum enabled logging level is `WARN`, and it can be modified in multiple ways: + +* CMake configuration variable `LIBCUDF_LOGGING_LEVEL` - sets the minimum level of logging that +will be compiled in the build. +Available levels are `TRACE`, `DEBUG`, `INFO`, `WARN`, `ERROR`, `CRITICAL`, and `OFF`. +* Environment variable `LIBCUDF_LOGGING_LEVEL` - sets the minimum logging level during +initialization. If this setting is higher than the compile-time CMake variable, any logging levels +in between the two settings will be excluded from the written log. The available levels are the same +as for the CMake variable. +* Global logger object exposed via `cudf::logger()` - sets the minimum logging level at runtime. +For example, calling `cudf::logger().set_level(spdlog::level::err)`, will exclude any messages that +are not errors or critical errors. This API should not be used within libcudf to manipulate logging, +its purpose is to allow upstream users to configure libcudf logging to fit their application. + +By default, logging messages are output to stderr. +Setting the environment variable `LIBCUDF_DEBUG_LOG_FILE` redirects the log to a file with the +specified path (can be relative to the current directory). +Upstream users can also manipulate `cudf::logger().sinks()` to add sinks or divert the log to +standard output or even a custom spdlog sink. + # Data Types Columns may contain data of a number of types (see `enum class type_id` in `include/cudf/types.hpp`) diff --git a/cpp/include/cudf/detail/utilities/logger.hpp b/cpp/include/cudf/detail/utilities/logger.hpp new file mode 100644 index 00000000000..8c1c3c28df8 --- /dev/null +++ b/cpp/include/cudf/detail/utilities/logger.hpp @@ -0,0 +1,27 @@ +/* + * Copyright (c) 2023, NVIDIA CORPORATION. + * + * 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 + +// Log messages that require computation should only be used at level TRACE and DEBUG +#define CUDF_LOG_TRACE(...) SPDLOG_LOGGER_TRACE(&cudf::logger(), __VA_ARGS__) +#define CUDF_LOG_DEBUG(...) SPDLOG_LOGGER_DEBUG(&cudf::logger(), __VA_ARGS__) +#define CUDF_LOG_INFO(...) SPDLOG_LOGGER_INFO(&cudf::logger(), __VA_ARGS__) +#define CUDF_LOG_WARN(...) SPDLOG_LOGGER_WARN(&cudf::logger(), __VA_ARGS__) +#define CUDF_LOG_ERROR(...) SPDLOG_LOGGER_ERROR(&cudf::logger(), __VA_ARGS__) +#define CUDF_LOG_CRITICAL(...) SPDLOG_LOGGER_CRITICAL(&cudf::logger(), __VA_ARGS__) diff --git a/cpp/include/cudf/utilities/logger.hpp b/cpp/include/cudf/utilities/logger.hpp new file mode 100644 index 00000000000..a39df064f44 --- /dev/null +++ b/cpp/include/cudf/utilities/logger.hpp @@ -0,0 +1,46 @@ +/* + * Copyright (c) 2023, NVIDIA CORPORATION. + * + * 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 + +namespace cudf { + +/** + * @brief Returns the global logger. + * + * This is a global instance of a spdlog logger. It can be used to configure logging behavior in + * libcudf. + * + * Examples: + * @code{.cpp} + * // Turn off logging at runtime + * cudf::logger().set_level(spdlog::level::off); + * // Add a stdout sink to the logger + * cudf::logger().sinks().push_back(std::make_shared()); + * // Replace the default sink + * cudf::logger().sinks() ={std::make_shared()}; + * @endcode + * + * Note: Changes to the sinks are not thread safe and should only be done during global + * initialization. + * + * @return spdlog::logger& The logger. + */ +spdlog::logger& logger(); + +} // namespace cudf diff --git a/cpp/src/io/utilities/config_utils.cpp b/cpp/src/io/utilities/config_utils.cpp index 2d1da31a08f..0f8961334cf 100644 --- a/cpp/src/io/utilities/config_utils.cpp +++ b/cpp/src/io/utilities/config_utils.cpp @@ -23,12 +23,6 @@ namespace cudf::io::detail { -std::string getenv_or(std::string const& env_var_name, std::string_view default_val) -{ - auto const env_val = std::getenv(env_var_name.c_str()); - return std::string{(env_val == nullptr) ? default_val : env_val}; -} - namespace cufile_integration { namespace { diff --git a/cpp/src/io/utilities/config_utils.hpp b/cpp/src/io/utilities/config_utils.hpp index 4f6a14091cf..74df1375e6f 100644 --- a/cpp/src/io/utilities/config_utils.hpp +++ b/cpp/src/io/utilities/config_utils.hpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2021-2022, NVIDIA CORPORATION. + * Copyright (c) 2021-2023, NVIDIA CORPORATION. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -15,6 +15,8 @@ */ #pragma once +#include + #include #include @@ -28,6 +30,13 @@ template T getenv_or(std::string_view env_var_name, T default_val) { auto const env_val = std::getenv(env_var_name.data()); + if (env_val != nullptr) { + CUDF_LOG_INFO("Environment variable {} read as {}", env_var_name, env_val); + } else { + CUDF_LOG_INFO( + "Environment variable {} is not set, using default value {}", env_var_name, default_val); + } + if (env_val == nullptr) { return default_val; } std::stringstream sstream(env_val); diff --git a/cpp/src/io/utilities/hostdevice_vector.hpp b/cpp/src/io/utilities/hostdevice_vector.hpp index 01e1616b6e2..5a551998d21 100644 --- a/cpp/src/io/utilities/hostdevice_vector.hpp +++ b/cpp/src/io/utilities/hostdevice_vector.hpp @@ -30,6 +30,13 @@ #include +inline bool hostdevice_vector_uses_pageable_buffer() +{ + static bool const use_pageable = + cudf::io::detail::getenv_or("LIBCUDF_IO_PREFER_PAGEABLE_TMP_MEMORY", 0); + return use_pageable; +} + /** * @brief A helper class that wraps fixed-length device memory for the GPU, and * a mirror host pinned memory for the CPU. @@ -56,9 +63,7 @@ class hostdevice_vector { { CUDF_EXPECTS(initial_size <= max_size, "initial_size cannot be larger than max_size"); - auto const use_pageable_buffer = - cudf::io::detail::getenv_or("LIBCUDF_IO_PREFER_PAGEABLE_TMP_MEMORY", 0); - if (use_pageable_buffer) { + if (hostdevice_vector_uses_pageable_buffer()) { h_data_owner = thrust::host_vector(); } else { h_data_owner = thrust::host_vector>(); diff --git a/cpp/src/utilities/logger.cpp b/cpp/src/utilities/logger.cpp new file mode 100644 index 00000000000..91950850e3b --- /dev/null +++ b/cpp/src/utilities/logger.cpp @@ -0,0 +1,81 @@ +/* + * Copyright (c) 2023, NVIDIA CORPORATION. + * + * 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 "spdlog/sinks/stdout_sinks.h" +#include + +#include + +namespace { + +/** + * @brief Creates a sink for libcudf logging. + * + * Returns a file sink if the file name has been specified, otherwise returns a stderr sink. + */ +[[nodiscard]] spdlog::sink_ptr make_libcudf_sink() +{ + if (auto filename = std::getenv("LIBCUDF_DEBUG_LOG_FILE"); filename != nullptr) { + return std::make_shared(filename, true); + } else { + return std::make_shared(); + } +} + +/** + * @brief Converts the level name into the `spdlog` level enum. + */ +[[nodiscard]] spdlog::level::level_enum libcudf_log_level() +{ + auto const env_level = std::getenv("LIBCUDF_LOGGING_LEVEL"); + if (env_level == nullptr) { return spdlog::level::warn; } + + auto const env_lvl_str = std::string(env_level); + if (env_lvl_str == "TRACE") return spdlog::level::trace; + if (env_lvl_str == "DEBUG") return spdlog::level::debug; + if (env_lvl_str == "INFO") return spdlog::level::info; + if (env_lvl_str == "WARN") return spdlog::level::warn; + if (env_lvl_str == "ERROR") return spdlog::level::err; + if (env_lvl_str == "CRITICAL") return spdlog::level::critical; + if (env_lvl_str == "OFF") return spdlog::level::off; + + CUDF_FAIL("Invalid value for LIBCUDF_LOGGING_LEVEL environment variable"); +} + +/** + * @brief Simple wrapper around a spdlog::logger that performs cuDF-specific initialization. + */ +struct logger_wrapper { + spdlog::logger logger_; + + logger_wrapper() : logger_{"CUDF", make_libcudf_sink()} + { + logger_.set_pattern("[%6t][%H:%M:%S:%f][%-6l] %v"); + logger_.set_level(libcudf_log_level()); + logger_.flush_on(spdlog::level::warn); + } +}; + +} // namespace + +spdlog::logger& cudf::logger() +{ + static logger_wrapper wrapped{}; + return wrapped.logger_; +} diff --git a/cpp/tests/CMakeLists.txt b/cpp/tests/CMakeLists.txt index 13cb1739ae9..7c021a73eb5 100644 --- a/cpp/tests/CMakeLists.txt +++ b/cpp/tests/CMakeLists.txt @@ -285,6 +285,7 @@ ConfigureTest( utilities_tests/column_utilities_tests.cpp utilities_tests/column_wrapper_tests.cpp utilities_tests/lists_column_wrapper_tests.cpp + utilities_tests/logger_tests.cpp utilities_tests/default_stream_tests.cpp utilities_tests/type_check_tests.cpp ) diff --git a/cpp/tests/utilities_tests/logger_tests.cpp b/cpp/tests/utilities_tests/logger_tests.cpp new file mode 100644 index 00000000000..9d44e9d8247 --- /dev/null +++ b/cpp/tests/utilities_tests/logger_tests.cpp @@ -0,0 +1,77 @@ +/* + * Copyright (c) 2023, NVIDIA CORPORATION. + * + * 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 + +#include + +class LoggerTest : public cudf::test::BaseFixture { + std::ostringstream oss; + spdlog::level::level_enum prev_level; + std::vector prev_sinks; + + public: + LoggerTest() : prev_level{cudf::logger().level()}, prev_sinks{cudf::logger().sinks()} + { + cudf::logger().sinks() = {std::make_shared(oss)}; + cudf::logger().set_formatter( + std::unique_ptr(new spdlog::pattern_formatter("%v"))); + } + ~LoggerTest() + { + cudf::logger().set_level(prev_level); + cudf::logger().sinks() = prev_sinks; + } + + void clear_sink() { oss.str(""); } + std::string sink_content() { return oss.str(); } +}; + +TEST_F(LoggerTest, Basic) +{ + cudf::logger().critical("crit msg"); + ASSERT_EQ(this->sink_content(), "crit msg\n"); +} + +TEST_F(LoggerTest, DefaultLevel) +{ + cudf::logger().trace("trace"); + cudf::logger().debug("debug"); + cudf::logger().info("info"); + cudf::logger().warn("warn"); + cudf::logger().error("error"); + cudf::logger().critical("critical"); + ASSERT_EQ(this->sink_content(), "warn\nerror\ncritical\n"); +} + +TEST_F(LoggerTest, CustomLevel) +{ + cudf::logger().set_level(spdlog::level::warn); + cudf::logger().info("info"); + cudf::logger().warn("warn"); + ASSERT_EQ(this->sink_content(), "warn\n"); + + this->clear_sink(); + + cudf::logger().set_level(spdlog::level::debug); + cudf::logger().trace("trace"); + cudf::logger().debug("debug"); + ASSERT_EQ(this->sink_content(), "debug\n"); +} diff --git a/dependencies.yaml b/dependencies.yaml index 48b5bfe53d4..7b623d58425 100644 --- a/dependencies.yaml +++ b/dependencies.yaml @@ -103,7 +103,9 @@ dependencies: - librmm=23.04.* - output_types: conda packages: + - fmt>=9.1.0,<10 - librdkafka=1.7.0 + - spdlog>=1.11.0,<1.12 build_python: common: - output_types: [conda, requirements]