Add logging to libcudf

conda/recipes/libcudf/meta.yaml

@@ -125,6 +125,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
@@ -275,6 +276,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

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})
@@ -596,6 +597,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
@@ -676,8 +678,11 @@ if(NOT USE_NVTX)
   target_compile_definitions(cudf PUBLIC NVTX_DISABLE)
 endif()
 
+# Define RMM logging level
+target_compile_definitions(cudf PUBLIC "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)

cpp/doxygen/developer_guide/DEVELOPER_GUIDE.md

@@ -901,6 +901,42 @@ 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, messages below the `INFO` level are excluded from the log. In public builds, the code
+that logs at these 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 `INFO`, and it can be modified in multiple ways:
+
+* CMake configuration variable `LIBCUDF_LOGGING_LEVEL` - controls 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`, with the same values as the CMake variable.
+The difference is that disabled levels are present in the build, but the messages are excluded from
+the log.
+* Global logger object exposed via `cudf::logger()`. 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.
+
+The default log file is `cudf_log.txt` in the current working directory.
+The environment variable `LIBCUDF_DEBUG_LOG_FILE` can be set to specify the path and file name.
+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`)

cpp/include/cudf/detail/utilities/logger.hpp

@@ -0,0 +1,29 @@
+/*
+ * 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 <cudf/utilities/logger.hpp>
+
+// The default is INFO, but it should be used sparingly, so that by default a log file is only
+// output if there is important information, warnings, errors, and critical failures
+// 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__)

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 <spdlog/spdlog.h>
+
+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<spdlog::sinks::stdout_sink_mt>());
+ * // Replace the default sink
+ * cudf::logger().sinks() ={std::make_shared<spdlog::sinks::stderr_sink_mt>()};
+ * @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

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 {

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 <cudf/detail/utilities/logger.hpp>
+
 #include <sstream>
 #include <string>
 
@@ -28,6 +30,13 @@ template <typename T>
 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);

cpp/src/io/utilities/hostdevice_vector.hpp

@@ -30,6 +30,13 @@
 
 #include <variant>
 
+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<T>();
     } else {
       h_data_owner = thrust::host_vector<T, cudf::detail::pinned_allocator<T>>();

cpp/src/utilities/logger.cpp

@@ -0,0 +1,79 @@
+/*
+ * 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 <cudf/utilities/error.hpp>
+#include <cudf/utilities/logger.hpp>
+
+#include "spdlog/sinks/stdout_sinks.h"
+#include <spdlog/sinks/basic_file_sink.h>
+
+#include <string>
+
+namespace {
+
+/**
+ * @brief TODO
+ */
+[[nodiscard]] spdlog::sink_ptr make_libcudf_sink()
+{
+  if (auto filename = std::getenv("LIBCUDF_DEBUG_LOG_FILE"); filename != nullptr) {
+    return std::make_shared<spdlog::sinks::basic_file_sink_mt>(filename, true);
+  } else {
+    return std::make_shared<spdlog::sinks::stdout_sink_mt>();
+  }
+}
+
+/**
+ * @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_;
+}

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
 )